[May 24 16:43:33] DEBUG[13482] config.c: Parsing /etc/asterisk/logger.conf [May 24 16:43:33] VERBOSE[13482] logger.c: Asterisk Event Logger restarted [May 24 16:43:33] DEBUG[13482] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [May 24 16:43:33] DEBUG[13482] res_config_pgsql.c: PostgreSQL RealTime: Insert SQL: INSERT INTO queue_log (eventdate, cdr_uniqueid, queuename, agent, event, data1, data2, data3, data4) VALUES ('2010-05-24 16:43:33', 'NONE', 'NONE', 'NONE', 'CONFIGRELOAD', '', '', '', '') [May 24 16:43:33] DEBUG[13482] res_config_pgsql.c: PostgreSQL RealTime: row inserted on table: queue_log, id: 0 [May 24 16:43:33] VERBOSE[13482] logger.c: Asterisk Queue Logger restarted [May 24 16:43:48] DEBUG[4053] acl.c: Found IP address for this socket [May 24 16:43:48] DEBUG[4053] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:43:48] DEBUG[4053] chan_sip.c: Allocating new SIP dialog for 58eee4585a1e411a55f4b29a409ba2e5@192.168.222.33 - OPTIONS (No RTP) [May 24 16:43:48] DEBUG[4053] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [May 24 16:43:48] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:44:01] DEBUG[4053] chan_sip.c: Allocating new SIP dialog for 50e261773c4020ee40f9dab411d5c250@192.168.222.32 - OPTIONS (No RTP) [May 24 16:44:01] DEBUG[4053] acl.c: Found IP address for this socket [May 24 16:44:01] DEBUG[4053] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:44:01] DEBUG[4053] chan_sip.c: Initializing initreq for method OPTIONS - callid 3d6201181fe7fac605b38f703cd3acd1@192.168.222.32 [May 24 16:44:01] DEBUG[4053] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:44:01] DEBUG[4053] chan_sip.c: Stopping retransmission on '3d6201181fe7fac605b38f703cd3acd1@192.168.222.32' of Request 102: Match Found [May 24 16:44:01] DEBUG[4053] chan_sip.c: Destroying SIP dialog 3d6201181fe7fac605b38f703cd3acd1@192.168.222.32 [May 24 16:44:01] DEBUG[4040] chan_iax2.c: ip callno count decremented to 0 for 192.168.222.3 [May 24 16:44:01] DEBUG[4050] chan_iax2.c: ip callno count incremented to 1 for 192.168.222.3 [May 24 16:44:01] DEBUG[4041] chan_iax2.c: schedule decrement of callno used for 192.168.222.3 in 60 seconds [May 24 16:44:01] DEBUG[4041] chan_iax2.c: Peer TRUNK_TEST_VIRT: got pong, lastms 9, historicms 9, maxms 2000 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Allocating new SIP dialog for 4fe69c985951efea7940f6155444071b@192.168.222.32 - OPTIONS (No RTP) [May 24 16:44:20] DEBUG[4053] acl.c: Found IP address for this socket [May 24 16:44:20] DEBUG[4053] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Initializing initreq for method OPTIONS - callid 3ef859ab058da074743eb34136e658c8@192.168.222.32 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 0 [ 43]: OPTIONS sip:100@192.168.222.45:8468 SIP/2.0 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK19ca7eb6;rport [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as1073e31a [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 4 [ 33]: To: [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 5 [ 38]: Contact: [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 6 [ 56]: Call-ID: 3ef859ab058da074743eb34136e658c8@192.168.222.32 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.2.8-rc1 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 9 [ 35]: Date: Mon, 24 May 2010 21:44:20 GMT [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 24 16:44:20] VERBOSE[4053] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.222.45:8468: OPTIONS sip:100@192.168.222.45:8468 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK19ca7eb6;rport Max-Forwards: 70 From: "asterisk" ;tag=as1073e31a To: Contact: Call-ID: 3ef859ab058da074743eb34136e658c8@192.168.222.32 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.8-rc1 Date: Mon, 24 May 2010 21:44:20 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [May 24 16:44:20] DEBUG[4053] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2735 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:44:20] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.32:5060;rport=5060;received=192.168.222.32;branch=z9hG4bK19ca7eb6 Call-ID: 3ef859ab058da074743eb34136e658c8@192.168.222.32 From: "asterisk" ;tag=as1073e31a To: CSeq: 102 OPTIONS Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS Accept: message/sipfrag;version=2.0, application/sdp, application/sdp Supported: replaces, 100rel Allow-Events: refer Content-Length: 0 <-------------> [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 192.168.222.32:5060;rport=5060;received=192.168.222.32;branch=z9hG4bK19ca7eb6 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 2 [ 56]: Call-ID: 3ef859ab058da074743eb34136e658c8@192.168.222.32 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as1073e31a [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 4 [ 28]: To: [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 6 [ 97]: Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 7 [ 69]: Accept: message/sipfrag;version=2.0, application/sdp, application/sdp [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 8 [ 27]: Supported: replaces, 100rel [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 9 [ 19]: Allow-Events: refer [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 10 [ 18]: Content-Length: 0 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Header 11 [ 0]: [May 24 16:44:20] VERBOSE[4053] chan_sip.c: --- (11 headers 0 lines) --- [May 24 16:44:20] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2735 [May 24 16:44:20] DEBUG[4053] chan_sip.c: Stopping retransmission on '3ef859ab058da074743eb34136e658c8@192.168.222.32' of Request 102: Match Found [May 24 16:44:20] DEBUG[4053] chan_sip.c: Destroying SIP dialog 3ef859ab058da074743eb34136e658c8@192.168.222.32 [May 24 16:44:20] VERBOSE[4053] chan_sip.c: Really destroying SIP dialog '3ef859ab058da074743eb34136e658c8@192.168.222.32' Method: OPTIONS [May 24 16:44:20] DEBUG[4053] chan_sip.c: Auto destroying SIP dialog '58eee4585a1e411a55f4b29a409ba2e5@192.168.222.33' [May 24 16:44:20] DEBUG[4053] chan_sip.c: Destroying SIP dialog 58eee4585a1e411a55f4b29a409ba2e5@192.168.222.33 [May 24 16:44:20] VERBOSE[4053] chan_sip.c: Really destroying SIP dialog '58eee4585a1e411a55f4b29a409ba2e5@192.168.222.33' Method: OPTIONS [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> INVITE sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj21ddc83a-dd36-4980-b5bf-422792472c86 Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: Contact: "miguel" Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 834 INVITE Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS Supported: replaces, 100rel Content-Type: application/sdp Content-Length: 320 v=0 o=laptop-miguel 3483726774 0 IN IP4 192.168.222.45 s=sflphone c=IN IP4 192.168.222.45 t=0 0 m=audio 29828 RTP/AVP 3 0 8 9 110 111 112 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:110 speex/8000 a=rtpmap:111 speex/16000 a=rtpmap:112 speex/32000 a=sendrecv <-------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 0 [ 38]: INVITE sip:1009@192.168.222.32 SIP/2.0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj21ddc83a-dd36-4980-b5bf-422792472c86 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 4 [ 29]: To: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 5 [ 47]: Contact: "miguel" [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 6 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 7 [ 16]: CSeq: 834 INVITE [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 8 [ 97]: Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 9 [ 27]: Supported: replaces, 100rel [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 11 [ 21]: Content-Length: 320 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 12 [ 0]: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 0 [ 3]: v=0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 1 [ 50]: o=laptop-miguel 3483726774 0 IN IP4 192.168.222.45 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 2 [ 10]: s=sflphone [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.222.45 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 4 [ 5]: t=0 0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 5 [ 41]: m=audio 29828 RTP/AVP 3 0 8 9 110 111 112 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 6 [ 19]: a=rtpmap:3 GSM/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 9 [ 20]: a=rtpmap:9 G722/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 10 [ 23]: a=rtpmap:110 speex/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 11 [ 24]: a=rtpmap:111 speex/16000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 12 [ 24]: a=rtpmap:112 speex/32000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 13 [ 10]: a=sendrecv [May 24 16:44:37] VERBOSE[4053] chan_sip.c: --- (12 headers 14 lines) --- [May 24 16:44:37] DEBUG[4053] acl.c: Found IP address for this socket [May 24 16:44:37] DEBUG[4053] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:44:37] VERBOSE[4053] netsock.c: == Using SIP RTP CoS mark 5 [May 24 16:44:37] VERBOSE[4053] netsock.c: == Using UDPTL CoS mark 5 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Setting NAT on RTP to Off [May 24 16:44:37] DEBUG[4053] chan_sip.c: Setting NAT on UDPTL to Off [May 24 16:44:37] DEBUG[4053] chan_sip.c: Allocating new SIP dialog for 74a43ae7-c446-49df-82d2-438d55ebb357 - INVITE (With RTP) [May 24 16:44:37] DEBUG[4053] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 16:44:37] DEBUG[4053] chan_sip.c: Begin: parsing SIP "Supported: replaces, 100rel" [May 24 16:44:37] DEBUG[4053] chan_sip.c: Found SIP option: -replaces- [May 24 16:44:37] DEBUG[4053] chan_sip.c: Matched SIP option: replaces [May 24 16:44:37] DEBUG[4053] chan_sip.c: Found SIP option: -100rel- [May 24 16:44:37] DEBUG[4053] chan_sip.c: Matched SIP option: 100rel [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Sending to 192.168.222.45 : 8468 (no NAT) [May 24 16:44:37] DEBUG[4053] chan_sip.c: Initializing initreq for method INVITE - callid 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Using INVITE request as basis request - 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found peer '100' for '100' from 192.168.222.45:8468 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Setting NAT on RTP to Off [May 24 16:44:37] DEBUG[4053] chan_sip.c: Setting NAT on UDPTL to Off [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- Reliably Transmitting (no NAT) to 192.168.222.45:8468 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.222.45:8468;branch=z9hG4bKPj21ddc83a-dd36-4980-b5bf-422792472c86;received=192.168.222.45;rport=8468 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as322e1740 Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 834 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="64e212d8" Content-Length: 0 <------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2738 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Scheduling destruction of SIP dialog '74a43ae7-c446-49df-82d2-438d55ebb357' in 6400 ms (Method: INVITE) [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> ACK sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj21ddc83a-dd36-4980-b5bf-422792472c86 Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as322e1740 Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 834 ACK Content-Length: 0 <-------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 0 [ 35]: ACK sip:1009@192.168.222.32 SIP/2.0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj21ddc83a-dd36-4980-b5bf-422792472c86 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 4 [ 44]: To: ;tag=as322e1740 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 5 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 6 [ 13]: CSeq: 834 ACK [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 7 [ 18]: Content-Length: 0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 8 [ 0]: [May 24 16:44:37] VERBOSE[4053] chan_sip.c: --- (8 headers 0 lines) --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 16:44:37] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2738 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Stopping retransmission on '74a43ae7-c446-49df-82d2-438d55ebb357' of Response 834: Match Found [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> INVITE sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj44a37170-b5d7-44ba-b9ad-1801fc6e2492 Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: Contact: "miguel" Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 835 INVITE Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS Supported: replaces, 100rel Authorization: Digest username="100", realm="asterisk", nonce="64e212d8", uri="sip:1009@192.168.222.32", response="71bb542083be62b687222a1fc2ed1684", algorithm=MD5 Content-Type: application/sdp Content-Length: 320 v=0 o=laptop-miguel 3483726774 0 IN IP4 192.168.222.45 s=sflphone c=IN IP4 192.168.222.45 t=0 0 m=audio 29828 RTP/AVP 3 0 8 9 110 111 112 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:110 speex/8000 a=rtpmap:111 speex/16000 a=rtpmap:112 speex/32000 a=sendrecv <-------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 0 [ 38]: INVITE sip:1009@192.168.222.32 SIP/2.0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj44a37170-b5d7-44ba-b9ad-1801fc6e2492 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 4 [ 29]: To: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 5 [ 47]: Contact: "miguel" [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 6 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 7 [ 16]: CSeq: 835 INVITE [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 8 [ 97]: Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 9 [ 27]: Supported: replaces, 100rel [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 10 [163]: Authorization: Digest username="100", realm="asterisk", nonce="64e212d8", uri="sip:1009@192.168.222.32", response="71bb542083be62b687222a1fc2ed1684", algorithm=MD5 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 12 [ 21]: Content-Length: 320 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 13 [ 0]: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 0 [ 3]: v=0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 1 [ 50]: o=laptop-miguel 3483726774 0 IN IP4 192.168.222.45 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 2 [ 10]: s=sflphone [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.222.45 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 4 [ 5]: t=0 0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 5 [ 41]: m=audio 29828 RTP/AVP 3 0 8 9 110 111 112 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 6 [ 19]: a=rtpmap:3 GSM/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 9 [ 20]: a=rtpmap:9 G722/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 10 [ 23]: a=rtpmap:110 speex/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 11 [ 24]: a=rtpmap:111 speex/16000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 12 [ 24]: a=rtpmap:112 speex/32000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 13 [ 10]: a=sendrecv [May 24 16:44:37] VERBOSE[4053] chan_sip.c: --- (13 headers 14 lines) --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Sending to 192.168.222.45 : 8468 (no NAT) [May 24 16:44:37] DEBUG[4053] chan_sip.c: Initializing initreq for method INVITE - callid 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Using INVITE request as basis request - 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found peer '100' for '100' from 192.168.222.45:8468 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Setting NAT on RTP to Off [May 24 16:44:37] DEBUG[4053] chan_sip.c: Setting NAT on UDPTL to Off [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP o=laptop-miguel 3483726774 0 IN IP4 192.168.222.45... UNSUPPORTED. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP s=sflphone... UNSUPPORTED. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.222.45... OK. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 3 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 0 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 8 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 9 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 110 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 111 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 112 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format GSM for ID 3 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format PCMU for ID 0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format PCMA for ID 8 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format G722 for ID 9 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 110 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:110 speex/8000... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 111 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:111 speex/16000... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 112 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:112 speex/32000... OK. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x1a1e (gsm|ulaw|alaw|g726|speex|g726aal2|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Peer audio RTP is at port 192.168.222.45:29828 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Peer doesn't provide T.38 UDPTL [May 24 16:44:37] DEBUG[4053] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [May 24 16:44:37] DEBUG[4053] chan_sip.c: Checking SIP call limits for device 100 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Updating call counter for incoming call [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Looking for 1009 in default (domain 192.168.222.32) [May 24 16:44:37] DEBUG[4053] chan_sip.c: *** Our native formats are 0x8 (alaw) [May 24 16:44:37] DEBUG[4053] chan_sip.c: *** Joint capabilities are 0xe (gsm|ulaw|alaw) [May 24 16:44:37] DEBUG[4053] chan_sip.c: *** Our capabilities are 0xe (gsm|ulaw|alaw) [May 24 16:44:37] DEBUG[4053] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [May 24 16:44:37] DEBUG[4053] chan_sip.c: This channel will not be able to handle video. [May 24 16:44:37] DEBUG[4053] chan_sip.c: build_route: Contact hop: "miguel" [May 24 16:44:37] VERBOSE[4053] chan_sip.c: list_route: hop: [May 24 16:44:37] DEBUG[4053] chan_sip.c: SIP/100-00000004: New call is still down.... Trying... [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- Transmitting (no NAT) to 192.168.222.45:8468 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.222.45:8468;branch=z9hG4bKPj44a37170-b5d7-44ba-b9ad-1801fc6e2492;received=192.168.222.45;rport=8468 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 835 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:44:37] DEBUG[4028] devicestate.c: No provider found, checking channel drivers for SIP - 100 [May 24 16:44:37] DEBUG[4028] chan_sip.c: Checking device state for peer 100 [May 24 16:44:37] DEBUG[4028] devicestate.c: Changing state for SIP/100 - state 1 (Not in use) [May 24 16:44:37] DEBUG[4028] devicestate.c: device 'SIP/100' state '1' [May 24 16:44:37] DEBUG[13490] pbx.c: Launching 'Dial' [May 24 16:44:37] VERBOSE[13490] pbx.c: -- Executing [1009@default:1] Dial("SIP/100-00000004", "SIP/TRUNK_INTER_MAQUINAS/1004") in new stack [May 24 16:44:37] DEBUG[4056] app_queue.c: Device 'SIP/100' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 24 16:44:37] DEBUG[13490] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw) [May 24 16:44:37] VERBOSE[13490] netsock.c: == Using SIP RTP CoS mark 5 [May 24 16:44:37] VERBOSE[13490] netsock.c: == Using UDPTL CoS mark 5 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Allocating new SIP dialog for 34aef1551bb7930c638d1bca262eccfd@192.168.222.32 - INVITE (With RTP) [May 24 16:44:37] DEBUG[13490] chan_sip.c: Setting NAT on RTP to Off [May 24 16:44:37] DEBUG[13490] chan_sip.c: Setting NAT on UDPTL to Off [May 24 16:44:37] DEBUG[13490] chan_sip.c: OBPROXY: Not applying OBproxy to this call [May 24 16:44:37] DEBUG[13490] acl.c: Found IP address for this socket [May 24 16:44:37] DEBUG[13490] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:44:37] DEBUG[13490] frame.c: Could not find preferred codec - Going for the best codec [May 24 16:44:37] DEBUG[13490] chan_sip.c: *** Our native formats are 0x8 (alaw) [May 24 16:44:37] DEBUG[13490] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [May 24 16:44:37] DEBUG[13490] chan_sip.c: *** Our capabilities are 0x2 (gsm) [May 24 16:44:37] DEBUG[13490] frame.c: Could not find preferred codec - Going for the best codec [May 24 16:44:37] DEBUG[13490] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [May 24 16:44:37] DEBUG[13490] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw) [May 24 16:44:37] DEBUG[13490] chan_sip.c: This channel will not be able to handle video. [May 24 16:44:37] DEBUG[13490] channel.c: Not copying variable DIALEDTIME. [May 24 16:44:37] DEBUG[13490] channel.c: Not copying variable ANSWEREDTIME. [May 24 16:44:37] DEBUG[13490] channel.c: Not copying variable DIALEDPEERNAME. [May 24 16:44:37] DEBUG[13490] channel.c: Not copying variable DIALEDPEERNUMBER. [May 24 16:44:37] DEBUG[13490] channel.c: Not copying variable DIALSTATUS. [May 24 16:44:37] DEBUG[13490] channel.c: Not copying variable SIPCALLID. [May 24 16:44:37] DEBUG[13490] channel.c: Not copying variable SIPDOMAIN. [May 24 16:44:37] DEBUG[13490] channel.c: Not copying variable SIPURI. [May 24 16:44:37] DEBUG[13490] chan_sip.c: Outgoing Call for 1004 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Updating call counter for outgoing call [May 24 16:44:37] DEBUG[13490] chan_sip.c: ** Our capability: 0x2 (gsm) Video flag: False Text flag: False [May 24 16:44:37] DEBUG[13490] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [May 24 16:44:37] VERBOSE[13490] chan_sip.c: Audio is at 192.168.222.32 port 13534 [May 24 16:44:37] VERBOSE[13490] chan_sip.c: Adding codec 0x2 (gsm) to SDP [May 24 16:44:37] VERBOSE[13490] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [May 24 16:44:37] DEBUG[13490] chan_sip.c: -- Done with adding codecs to SDP [May 24 16:44:37] DEBUG[13490] chan_sip.c: Done building SDP. Settling with this capability: 0x2 (gsm) [May 24 16:44:37] DEBUG[13490] chan_sip.c: Initializing initreq for method INVITE - callid 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 0 [ 38]: INVITE sip:1004@192.168.222.33 SIP/2.0 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7e653931;rport [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 3 [ 51]: From: "100" ;tag=as64cb91d5 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 4 [ 29]: To: [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 5 [ 33]: Contact: [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 6 [ 56]: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.2.8-rc1 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 9 [ 35]: Date: Mon, 24 May 2010 21:44:37 GMT [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 13 [ 19]: Content-Length: 270 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Header 14 [ 0]: [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 0 [ 3]: v=0 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 1 [ 50]: o=root 1923154938 1923154938 IN IP4 192.168.222.32 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 2 [ 26]: s=Asterisk PBX 1.6.2.8-rc1 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.222.32 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 4 [ 5]: t=0 0 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 5 [ 27]: m=audio 13534 RTP/AVP 3 101 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 6 [ 19]: a=rtpmap:3 GSM/8000 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 10 [ 10]: a=ptime:20 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Body 11 [ 10]: a=sendrecv [May 24 16:44:37] VERBOSE[13490] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.222.33:5060: INVITE sip:1004@192.168.222.33 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7e653931;rport Max-Forwards: 70 From: "100" ;tag=as64cb91d5 To: Contact: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.2.8-rc1 Date: Mon, 24 May 2010 21:44:37 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 270 v=0 o=root 1923154938 1923154938 IN IP4 192.168.222.32 s=Asterisk PBX 1.6.2.8-rc1 c=IN IP4 192.168.222.32 t=0 0 m=audio 13534 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [May 24 16:44:37] DEBUG[13490] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2741 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:44:37] VERBOSE[13490] app_dial.c: -- Called TRUNK_INTER_MAQUINAS/1004 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.33:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7e653931;received=192.168.222.32;rport=5060 From: "100" ;tag=as64cb91d5 To: ;tag=as3c4419aa Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 102 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="774515e4" Content-Length: 0 <-------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 0 [ 24]: SIP/2.0 401 Unauthorized [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7e653931;received=192.168.222.32;rport=5060 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 2 [ 51]: From: "100" ;tag=as64cb91d5 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 3 [ 44]: To: ;tag=as3c4419aa [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 4 [ 56]: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 6 [ 32]: Server: Asterisk PBX 1.6.2.8-rc1 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 9 [ 74]: WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="774515e4" [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 11 [ 0]: [May 24 16:44:37] VERBOSE[4053] chan_sip.c: --- (11 headers 0 lines) --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: Acked pending invite 102 [May 24 16:44:37] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2741 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Stopping retransmission on '50254fb032d586fe3a6d81987db9f31b@192.168.222.32' of Request 102: Match Found [May 24 16:44:37] DEBUG[4053] chan_sip.c: SIP response 401 to standard invite [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Transmitting (no NAT) to 192.168.222.33:5060: ACK sip:1004@192.168.222.33 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7e653931;rport Max-Forwards: 70 From: "100" ;tag=as64cb91d5 To: ;tag=as3c4419aa Contact: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.2.8-rc1 Content-Length: 0 --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: Trying to put 'ACK sip:100' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Auth attempt 1 on INVITE [May 24 16:44:37] DEBUG[4053] chan_sip.c: ** Our capability: 0x2 (gsm) Video flag: False Text flag: False [May 24 16:44:37] DEBUG[4053] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Audio is at 192.168.222.32 port 13534 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Adding codec 0x2 (gsm) to SDP [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [May 24 16:44:37] DEBUG[4053] chan_sip.c: -- Done with adding codecs to SDP [May 24 16:44:37] DEBUG[4053] chan_sip.c: Done building SDP. Settling with this capability: 0x2 (gsm) [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.222.33:5060: INVITE sip:1004@192.168.222.33 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK2e8b376a;rport Max-Forwards: 70 From: "100" ;tag=as64cb91d5 To: Contact: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.6.2.8-rc1 Authorization: Digest username="TRUNK_INTER_MAQUINAS", realm="asterisk", algorithm=MD5, uri="sip:1004@192.168.222.33", nonce="774515e4", response="59bd7fcfef9f03c9cb1b191be23ef216" Date: Mon, 24 May 2010 21:44:37 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 270 v=0 o=root 1923154938 1923154939 IN IP4 192.168.222.32 s=Asterisk PBX 1.6.2.8-rc1 c=IN IP4 192.168.222.32 t=0 0 m=audio 13534 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2743 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.33:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK2e8b376a;received=192.168.222.32;rport=5060 From: "100" ;tag=as64cb91d5 To: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 103 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <-------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK2e8b376a;received=192.168.222.32;rport=5060 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 2 [ 51]: From: "100" ;tag=as64cb91d5 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 3 [ 29]: To: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 4 [ 56]: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 6 [ 32]: Server: Asterisk PBX 1.6.2.8-rc1 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 9 [ 14]: Require: timer [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 11 [ 34]: Contact: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 13 [ 0]: [May 24 16:44:37] VERBOSE[4053] chan_sip.c: --- (13 headers 0 lines) --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: *** SIP TIMER: Cancelling retransmission #2743 - INVITE (got response) [May 24 16:44:37] DEBUG[4053] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '50254fb032d586fe3a6d81987db9f31b@192.168.222.32' Request 103: Found [May 24 16:44:37] DEBUG[4053] chan_sip.c: SIP response 100 to standard invite [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.33:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK2e8b376a;received=192.168.222.32;rport=5060 From: "100" ;tag=as64cb91d5 To: ;tag=as2b2bee60 Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 103 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Content-Length: 268 v=0 o=root 384439584 384439584 IN IP4 192.168.222.33 s=Asterisk PBX 1.6.2.8-rc1 c=IN IP4 192.168.222.33 t=0 0 m=audio 18332 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK2e8b376a;received=192.168.222.32;rport=5060 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 2 [ 51]: From: "100" ;tag=as64cb91d5 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 3 [ 44]: To: ;tag=as2b2bee60 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 4 [ 56]: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 6 [ 32]: Server: Asterisk PBX 1.6.2.8-rc1 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 9 [ 14]: Require: timer [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 11 [ 34]: Contact: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 13 [ 19]: Content-Length: 268 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 14 [ 0]: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 0 [ 3]: v=0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 1 [ 48]: o=root 384439584 384439584 IN IP4 192.168.222.33 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 2 [ 26]: s=Asterisk PBX 1.6.2.8-rc1 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.222.33 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 4 [ 5]: t=0 0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 5 [ 27]: m=audio 18332 RTP/AVP 3 101 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 6 [ 19]: a=rtpmap:3 GSM/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 10 [ 10]: a=ptime:20 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Body 11 [ 10]: a=sendrecv [May 24 16:44:37] VERBOSE[4053] chan_sip.c: --- (14 headers 12 lines) --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: Acked pending invite 103 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Stopping retransmission on '50254fb032d586fe3a6d81987db9f31b@192.168.222.32' of Request 103: Match Found [May 24 16:44:37] DEBUG[4053] chan_sip.c: SIP response 200 to standard invite [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP o=root 384439584 384439584 IN IP4 192.168.222.33... UNSUPPORTED. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP s=Asterisk PBX 1.6.2.8-rc1... UNSUPPORTED. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.222.33... OK. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 3 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found RTP audio format 101 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format GSM for ID 3 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Found audio description format telephone-event for ID 101 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [May 24 16:44:37] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Capabilities: us - 0x2 (gsm), peer - audio=0x2 (gsm)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x2 (gsm) [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Peer audio RTP is at port 192.168.222.33:18332 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Peer doesn't provide T.38 UDPTL [May 24 16:44:37] DEBUG[4053] chan_sip.c: We're settling with these formats: 0x2 (gsm) [May 24 16:44:37] DEBUG[4053] chan_sip.c: We have an owner, now see if we need to change this call [May 24 16:44:37] DEBUG[4053] chan_sip.c: Oooh, we need to change our audio formats since our peer supports only 0x2 (gsm) and not 0x8 (alaw) [May 24 16:44:37] DEBUG[4053] channel.c: Set channel SIP/TRUNK_INTER_MAQUINAS-00000005 to read format alaw [May 24 16:44:37] DEBUG[4053] channel.c: Set channel SIP/TRUNK_INTER_MAQUINAS-00000005 to write format alaw [May 24 16:44:37] DEBUG[4053] chan_sip.c: Updating call counter for outgoing call [May 24 16:44:37] DEBUG[4053] chan_sip.c: build_route: Contact hop: [May 24 16:44:37] VERBOSE[4053] chan_sip.c: list_route: hop: [May 24 16:44:37] DEBUG[4053] chan_sip.c: Session-Expires: 1800 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Refresher: UAS [May 24 16:44:37] DEBUG[4053] chan_sip.c: Session timer started: 2744 - 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Strict routing enforced for session 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: set_destination: Parsing for address/port to send to [May 24 16:44:37] VERBOSE[4053] chan_sip.c: set_destination: set destination to 192.168.222.33, port 5060 [May 24 16:44:37] VERBOSE[4053] chan_sip.c: Transmitting (no NAT) to 192.168.222.33:5060: ACK sip:1004@192.168.222.33 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK697df1d2;rport Max-Forwards: 70 From: "100" ;tag=as64cb91d5 To: ;tag=as2b2bee60 Contact: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 103 ACK User-Agent: Asterisk PBX 1.6.2.8-rc1 Content-Length: 0 --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: Trying to put 'ACK sip:100' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:44:37] DEBUG[4028] devicestate.c: No provider found, checking channel drivers for SIP - TRUNK_INTER_MAQUINAS [May 24 16:44:37] DEBUG[4028] chan_sip.c: Checking device state for peer TRUNK_INTER_MAQUINAS [May 24 16:44:37] DEBUG[4028] devicestate.c: Changing state for SIP/TRUNK_INTER_MAQUINAS - state 1 (Not in use) [May 24 16:44:37] DEBUG[4028] devicestate.c: device 'SIP/TRUNK_INTER_MAQUINAS' state '1' [May 24 16:44:37] VERBOSE[13490] app_dial.c: -- SIP/TRUNK_INTER_MAQUINAS-00000005 answered SIP/100-00000004 [May 24 16:44:37] DEBUG[4056] app_queue.c: Device 'SIP/TRUNK_INTER_MAQUINAS' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 24 16:44:37] DEBUG[4028] devicestate.c: No provider found, checking channel drivers for SIP - 100 [May 24 16:44:37] DEBUG[4028] chan_sip.c: Checking device state for peer 100 [May 24 16:44:37] DEBUG[4028] devicestate.c: Changing state for SIP/100 - state 1 (Not in use) [May 24 16:44:37] DEBUG[4028] devicestate.c: device 'SIP/100' state '1' [May 24 16:44:37] DEBUG[13490] chan_sip.c: SIP answering channel: SIP/100-00000004 [May 24 16:44:37] DEBUG[13490] rtp.c: Setting the marker bit due to a source update [May 24 16:44:37] DEBUG[4056] app_queue.c: Device 'SIP/100' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 24 16:44:37] DEBUG[13490] chan_sip.c: Setting framing from config on incoming call [May 24 16:44:37] DEBUG[13490] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True [May 24 16:44:37] DEBUG[13490] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [May 24 16:44:37] VERBOSE[13490] chan_sip.c: Audio is at 192.168.222.32 port 11236 [May 24 16:44:37] VERBOSE[13490] chan_sip.c: Adding codec 0x8 (alaw) to SDP [May 24 16:44:37] VERBOSE[13490] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [May 24 16:44:37] VERBOSE[13490] chan_sip.c: Adding codec 0x2 (gsm) to SDP [May 24 16:44:37] DEBUG[13490] chan_sip.c: -- Done with adding codecs to SDP [May 24 16:44:37] DEBUG[13490] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [May 24 16:44:37] VERBOSE[13490] chan_sip.c: <--- Reliably Transmitting (no NAT) to 192.168.222.45:8468 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.45:8468;branch=z9hG4bKPj44a37170-b5d7-44ba-b9ad-1801fc6e2492;received=192.168.222.45;rport=8468 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 835 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 258 v=0 o=root 16819587 16819587 IN IP4 192.168.222.32 s=Asterisk PBX 1.6.2.8-rc1 c=IN IP4 192.168.222.32 t=0 0 m=audio 11236 RTP/AVP 8 0 3 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [May 24 16:44:37] DEBUG[13490] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2745 [May 24 16:44:37] DEBUG[13490] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:44:37] DEBUG[13490] features.c: bridge answer set, chan answer set [May 24 16:44:37] DEBUG[13490] rtp.c: Setting the marker bit due to a source update [May 24 16:44:37] DEBUG[13490] rtp.c: Setting the marker bit due to a source update [May 24 16:44:37] DEBUG[13490] rtp.c: Cannot packet2packet bridge - raw formats are incompatible [May 24 16:44:37] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> ACK sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPjbe7f0230-7fb2-4c5f-8b8e-2d39ec990fe5 Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 835 ACK Content-Length: 0 <-------------> [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 0 [ 35]: ACK sip:1009@192.168.222.32 SIP/2.0 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPjbe7f0230-7fb2-4c5f-8b8e-2d39ec990fe5 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 4 [ 44]: To: ;tag=as63d8fdea [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 5 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 6 [ 13]: CSeq: 835 ACK [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 7 [ 18]: Content-Length: 0 [May 24 16:44:37] DEBUG[13490] rtp.c: Got RTCP report of 40 bytes [May 24 16:44:37] DEBUG[4053] chan_sip.c: Header 8 [ 0]: [May 24 16:44:37] VERBOSE[4053] chan_sip.c: --- (8 headers 0 lines) --- [May 24 16:44:37] DEBUG[4053] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 16:44:37] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2745 [May 24 16:44:37] DEBUG[4053] chan_sip.c: Stopping retransmission on '74a43ae7-c446-49df-82d2-438d55ebb357' of Response 835: Match Found [May 24 16:44:37] DEBUG[13490] chan_sip.c: Oooh, format changed to 2 gsm [May 24 16:44:37] DEBUG[13490] channel.c: Set channel SIP/100-00000004 to read format alaw [May 24 16:44:37] DEBUG[13490] channel.c: Set channel SIP/100-00000004 to write format alaw [May 24 16:44:37] DEBUG[13490] rtp.c: Ooh, format changed from unknown to gsm [May 24 16:44:37] DEBUG[13490] rtp.c: Created smoother: format: 2 ms: 20 len: 33 [May 24 16:44:37] DEBUG[13490] rtp.c: Ooh, format changed from unknown to gsm [May 24 16:44:37] DEBUG[13490] rtp.c: Created smoother: format: 2 ms: 20 len: 33 [May 24 16:44:42] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:44:44] DEBUG[13490] rtp.c: Got RTCP report of 84 bytes [May 24 16:44:47] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:44:48] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.33:5060 ---> OPTIONS sip:192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.33:5060;branch=z9hG4bK54c8f23e;rport Max-Forwards: 70 From: "asterisk" ;tag=as5906e152 To: Contact: Call-ID: 6575231d46ea453a76253e54274c3699@192.168.222.33 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.8-rc1 Date: Mon, 24 May 2010 21:44:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <-------------> [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 0 [ 34]: OPTIONS sip:192.168.222.32 SIP/2.0 [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.222.33:5060;branch=z9hG4bK54c8f23e;rport [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as5906e152 [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 4 [ 24]: To: [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 5 [ 38]: Contact: [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 6 [ 56]: Call-ID: 6575231d46ea453a76253e54274c3699@192.168.222.33 [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.2.8-rc1 [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 9 [ 35]: Date: Mon, 24 May 2010 21:44:48 GMT [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 24 16:44:48] DEBUG[4053] chan_sip.c: Header 13 [ 0]: [May 24 16:44:48] VERBOSE[4053] chan_sip.c: --- (13 headers 0 lines) --- [May 24 16:44:48] DEBUG[4053] acl.c: Found IP address for this socket [May 24 16:44:48] DEBUG[4053] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:44:48] DEBUG[4053] chan_sip.c: Allocating new SIP dialog for 6575231d46ea453a76253e54274c3699@192.168.222.33 - OPTIONS (No RTP) [May 24 16:44:48] DEBUG[4053] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [May 24 16:44:48] VERBOSE[4053] chan_sip.c: Looking for s in default (domain 192.168.222.32) [May 24 16:44:48] VERBOSE[4053] chan_sip.c: <--- Transmitting (no NAT) to 192.168.222.33:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.33:5060;branch=z9hG4bK54c8f23e;received=192.168.222.33;rport=5060 From: "asterisk" ;tag=as5906e152 To: ;tag=as234048bd Call-ID: 6575231d46ea453a76253e54274c3699@192.168.222.33 CSeq: 102 OPTIONS Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> [May 24 16:44:48] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:44:48] VERBOSE[4053] chan_sip.c: Scheduling destruction of SIP dialog '6575231d46ea453a76253e54274c3699@192.168.222.33' in 32000 ms (Method: OPTIONS) [May 24 16:44:50] DEBUG[13490] rtp.c: Got RTCP report of 84 bytes [May 24 16:44:51] DEBUG[13490] rtp.c: Got RTCP report of 44 bytes [May 24 16:44:51] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> INVITE sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj0e78f5da-1a13-481c-a5a1-a8ec1179163a Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Contact: "miguel" Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 836 INVITE Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS Supported: replaces, 100rel Content-Type: application/sdp Content-Length: 320 v=0 o=laptop-miguel 3483726774 1 IN IP4 192.168.222.45 s=sflphone c=IN IP4 192.168.222.45 t=0 0 m=audio 29828 RTP/AVP 3 0 8 9 110 111 112 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:110 speex/8000 a=rtpmap:111 speex/16000 a=rtpmap:112 speex/32000 a=sendonly <-------------> [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 0 [ 38]: INVITE sip:1009@192.168.222.32 SIP/2.0 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj0e78f5da-1a13-481c-a5a1-a8ec1179163a [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 4 [ 44]: To: ;tag=as63d8fdea [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 5 [ 47]: Contact: "miguel" [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 6 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 7 [ 16]: CSeq: 836 INVITE [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 8 [ 97]: Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 9 [ 27]: Supported: replaces, 100rel [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 11 [ 21]: Content-Length: 320 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 12 [ 0]: [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 0 [ 3]: v=0 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 1 [ 50]: o=laptop-miguel 3483726774 1 IN IP4 192.168.222.45 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 2 [ 10]: s=sflphone [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.222.45 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 4 [ 5]: t=0 0 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 5 [ 41]: m=audio 29828 RTP/AVP 3 0 8 9 110 111 112 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 6 [ 19]: a=rtpmap:3 GSM/8000 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 9 [ 20]: a=rtpmap:9 G722/8000 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 10 [ 23]: a=rtpmap:110 speex/8000 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 11 [ 24]: a=rtpmap:111 speex/16000 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 12 [ 24]: a=rtpmap:112 speex/32000 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Body 13 [ 10]: a=sendonly [May 24 16:44:51] VERBOSE[4053] chan_sip.c: --- (12 headers 14 lines) --- [May 24 16:44:51] DEBUG[4053] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Sending to 192.168.222.45 : 8468 (no NAT) [May 24 16:44:51] DEBUG[4053] chan_sip.c: Initializing initreq for method INVITE - callid 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing session-level SDP o=laptop-miguel 3483726774 1 IN IP4 192.168.222.45... UNSUPPORTED. [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing session-level SDP s=sflphone... UNSUPPORTED. [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.222.45... OK. [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found RTP audio format 3 [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found RTP audio format 0 [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found RTP audio format 8 [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found RTP audio format 9 [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found RTP audio format 110 [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found RTP audio format 111 [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found RTP audio format 112 [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found audio description format GSM for ID 3 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found audio description format PCMU for ID 0 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found audio description format PCMA for ID 8 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found audio description format G722 for ID 9 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 110 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:110 speex/8000... OK. [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 111 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:111 speex/16000... OK. [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 112 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:112 speex/32000... OK. [May 24 16:44:51] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=sendonly... OK. [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x1a1e (gsm|ulaw|alaw|g726|speex|g726aal2|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Peer audio RTP is at port 192.168.222.45:29828 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Peer doesn't provide T.38 UDPTL [May 24 16:44:51] DEBUG[4053] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [May 24 16:44:51] DEBUG[4053] chan_sip.c: We have an owner, now see if we need to change this call [May 24 16:44:51] DEBUG[4053] chan_sip.c: Got a SIP re-invite for call 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:51] DEBUG[4053] chan_sip.c: SIP/100-00000004: This call is UP.... [May 24 16:44:51] VERBOSE[4053] chan_sip.c: <--- Transmitting (no NAT) to 192.168.222.45:8468 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.222.45:8468;branch=z9hG4bKPj0e78f5da-1a13-481c-a5a1-a8ec1179163a;received=192.168.222.45;rport=8468 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 836 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 24 16:44:51] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Setting framing from config on incoming call [May 24 16:44:51] DEBUG[4053] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True [May 24 16:44:51] DEBUG[4053] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Audio is at 192.168.222.32 port 11236 [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Adding codec 0x8 (alaw) to SDP [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [May 24 16:44:51] VERBOSE[4053] chan_sip.c: Adding codec 0x2 (gsm) to SDP [May 24 16:44:51] DEBUG[4053] chan_sip.c: -- Done with adding codecs to SDP [May 24 16:44:51] DEBUG[4053] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [May 24 16:44:51] VERBOSE[4053] chan_sip.c: <--- Reliably Transmitting (no NAT) to 192.168.222.45:8468 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.45:8468;branch=z9hG4bKPj0e78f5da-1a13-481c-a5a1-a8ec1179163a;received=192.168.222.45;rport=8468 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 836 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 258 v=0 o=root 16819587 16819588 IN IP4 192.168.222.32 s=Asterisk PBX 1.6.2.8-rc1 c=IN IP4 192.168.222.32 t=0 0 m=audio 11236 RTP/AVP 8 0 3 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=silenceSupp:off - - - - a=ptime:20 a=recvonly <------------> [May 24 16:44:51] DEBUG[4053] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2749 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:44:51] DEBUG[13490] rtp.c: Setting the marker bit due to a source update [May 24 16:44:51] VERBOSE[13490] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/TRUNK_INTER_MAQUINAS-00000005 [May 24 16:44:51] DEBUG[13490] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [May 24 16:44:51] DEBUG[13490] rtp.c: Setting the marker bit due to a source update [May 24 16:44:51] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> ACK sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj1a48d7f1-8509-49a7-9a5d-17f774367a9e Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 836 ACK Content-Length: 0 <-------------> [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 0 [ 35]: ACK sip:1009@192.168.222.32 SIP/2.0 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj1a48d7f1-8509-49a7-9a5d-17f774367a9e [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:44:51] DEBUG[13490] channel.c: Set channel SIP/TRUNK_INTER_MAQUINAS-00000005 to write format gsm [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 4 [ 44]: To: ;tag=as63d8fdea [May 24 16:44:51] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 5 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 6 [ 13]: CSeq: 836 ACK [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 7 [ 18]: Content-Length: 0 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Header 8 [ 0]: [May 24 16:44:51] VERBOSE[4053] chan_sip.c: --- (8 headers 0 lines) --- [May 24 16:44:51] DEBUG[4053] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 16:44:51] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2749 [May 24 16:44:51] DEBUG[4053] chan_sip.c: Stopping retransmission on '74a43ae7-c446-49df-82d2-438d55ebb357' of Response 836: Match Found [May 24 16:44:51] DEBUG[13490] channel.c: Generator got voice, switching to phase locked mode [May 24 16:44:51] DEBUG[13490] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 24 16:44:52] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:44:52] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:44:53] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:44:54] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:44:56] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:44:57] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:44:57] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:44:58] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:44:59] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:45:00] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:45:01] DEBUG[4053] chan_sip.c: Allocating new SIP dialog for 00e24ffa2107e93d6d875cdd1d39515c@192.168.222.32 - OPTIONS (No RTP) [May 24 16:45:01] DEBUG[4053] acl.c: Found IP address for this socket [May 24 16:45:01] DEBUG[4053] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Initializing initreq for method OPTIONS - callid 5d2e136f6e1e0af55e33fe60256e8e35@192.168.222.32 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 0 [ 34]: OPTIONS sip:192.168.222.33 SIP/2.0 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7c5e30ec;rport [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as61d65d47 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 4 [ 24]: To: [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 5 [ 38]: Contact: [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 6 [ 56]: Call-ID: 5d2e136f6e1e0af55e33fe60256e8e35@192.168.222.32 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.2.8-rc1 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 9 [ 35]: Date: Mon, 24 May 2010 21:45:01 GMT [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 24 16:45:01] VERBOSE[4053] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.222.33:5060: OPTIONS sip:192.168.222.33 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7c5e30ec;rport Max-Forwards: 70 From: "asterisk" ;tag=as61d65d47 To: Contact: Call-ID: 5d2e136f6e1e0af55e33fe60256e8e35@192.168.222.32 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.8-rc1 Date: Mon, 24 May 2010 21:45:01 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [May 24 16:45:01] DEBUG[4053] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2750 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:45:01] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.33:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7c5e30ec;received=192.168.222.32;rport=5060 From: "asterisk" ;tag=as61d65d47 To: ;tag=as0d125442 Call-ID: 5d2e136f6e1e0af55e33fe60256e8e35@192.168.222.32 CSeq: 102 OPTIONS Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <-------------> [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7c5e30ec;received=192.168.222.32;rport=5060 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 2 [ 61]: From: "asterisk" ;tag=as61d65d47 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 3 [ 39]: To: ;tag=as0d125442 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 4 [ 56]: Call-ID: 5d2e136f6e1e0af55e33fe60256e8e35@192.168.222.32 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 6 [ 32]: Server: Asterisk PBX 1.6.2.8-rc1 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 9 [ 29]: Contact: [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 10 [ 23]: Accept: application/sdp [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Header 12 [ 0]: [May 24 16:45:01] VERBOSE[4053] chan_sip.c: --- (12 headers 0 lines) --- [May 24 16:45:01] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2750 [May 24 16:45:01] DEBUG[4053] chan_sip.c: Stopping retransmission on '5d2e136f6e1e0af55e33fe60256e8e35@192.168.222.32' of Request 102: Match Found [May 24 16:45:01] DEBUG[4053] chan_sip.c: Destroying SIP dialog 5d2e136f6e1e0af55e33fe60256e8e35@192.168.222.32 [May 24 16:45:01] VERBOSE[4053] chan_sip.c: Really destroying SIP dialog '5d2e136f6e1e0af55e33fe60256e8e35@192.168.222.32' Method: OPTIONS [May 24 16:45:01] DEBUG[4040] chan_iax2.c: ip callno count decremented to 0 for 192.168.222.3 [May 24 16:45:01] DEBUG[4045] chan_iax2.c: ip callno count incremented to 1 for 192.168.222.3 [May 24 16:45:01] DEBUG[4046] chan_iax2.c: schedule decrement of callno used for 192.168.222.3 in 60 seconds [May 24 16:45:01] DEBUG[4046] chan_iax2.c: Peer TRUNK_TEST_VIRT: got pong, lastms 12, historicms 12, maxms 2000 [May 24 16:45:02] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:45:02] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:45:03] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:45:04] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:45:05] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:45:06] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:45:07] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:45:07] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:45:09] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:45:10] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:45:11] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:45:12] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:45:12] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:45:13] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:45:14] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:45:16] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:45:17] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:45:17] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:45:18] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:45:19] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:45:20] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 2 '/var/lib/asterisk/moh/fpm-calm-river' [May 24 16:45:20] DEBUG[4053] chan_sip.c: Allocating new SIP dialog for 11219e0e4794de5426cbad40732019ff@192.168.222.32 - OPTIONS (No RTP) [May 24 16:45:20] DEBUG[4053] acl.c: Found IP address for this socket [May 24 16:45:20] DEBUG[4053] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Initializing initreq for method OPTIONS - callid 4748e9f01ea6e91f33f149e26dfc5789@192.168.222.32 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 0 [ 43]: OPTIONS sip:100@192.168.222.45:8468 SIP/2.0 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK137315aa;rport [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as1f8cb552 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 4 [ 33]: To: [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 5 [ 38]: Contact: [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 6 [ 56]: Call-ID: 4748e9f01ea6e91f33f149e26dfc5789@192.168.222.32 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.2.8-rc1 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 9 [ 35]: Date: Mon, 24 May 2010 21:45:20 GMT [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 24 16:45:20] VERBOSE[4053] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.222.45:8468: OPTIONS sip:100@192.168.222.45:8468 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK137315aa;rport Max-Forwards: 70 From: "asterisk" ;tag=as1f8cb552 To: Contact: Call-ID: 4748e9f01ea6e91f33f149e26dfc5789@192.168.222.32 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.8-rc1 Date: Mon, 24 May 2010 21:45:20 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [May 24 16:45:20] DEBUG[4053] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2753 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:45:20] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.32:5060;rport=5060;received=192.168.222.32;branch=z9hG4bK137315aa Call-ID: 4748e9f01ea6e91f33f149e26dfc5789@192.168.222.32 From: "asterisk" ;tag=as1f8cb552 To: CSeq: 102 OPTIONS Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS Accept: message/sipfrag;version=2.0, application/sdp, application/sdp Supported: replaces, 100rel Allow-Events: refer Content-Length: 0 <-------------> [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 192.168.222.32:5060;rport=5060;received=192.168.222.32;branch=z9hG4bK137315aa [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 2 [ 56]: Call-ID: 4748e9f01ea6e91f33f149e26dfc5789@192.168.222.32 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as1f8cb552 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 4 [ 28]: To: [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 6 [ 97]: Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 7 [ 69]: Accept: message/sipfrag;version=2.0, application/sdp, application/sdp [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 8 [ 27]: Supported: replaces, 100rel [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 9 [ 19]: Allow-Events: refer [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 10 [ 18]: Content-Length: 0 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Header 11 [ 0]: [May 24 16:45:20] VERBOSE[4053] chan_sip.c: --- (11 headers 0 lines) --- [May 24 16:45:20] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2753 [May 24 16:45:20] DEBUG[4053] chan_sip.c: Stopping retransmission on '4748e9f01ea6e91f33f149e26dfc5789@192.168.222.32' of Request 102: Match Found [May 24 16:45:20] DEBUG[4053] chan_sip.c: Destroying SIP dialog 4748e9f01ea6e91f33f149e26dfc5789@192.168.222.32 [May 24 16:45:20] VERBOSE[4053] chan_sip.c: Really destroying SIP dialog '4748e9f01ea6e91f33f149e26dfc5789@192.168.222.32' Method: OPTIONS [May 24 16:45:20] DEBUG[4053] chan_sip.c: Auto destroying SIP dialog '6575231d46ea453a76253e54274c3699@192.168.222.33' [May 24 16:45:20] DEBUG[4053] chan_sip.c: Destroying SIP dialog 6575231d46ea453a76253e54274c3699@192.168.222.33 [May 24 16:45:20] VERBOSE[4053] chan_sip.c: Really destroying SIP dialog '6575231d46ea453a76253e54274c3699@192.168.222.33' Method: OPTIONS [May 24 16:45:21] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 0 '/var/lib/asterisk/moh/fpm-sunshine' [May 24 16:45:22] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:45:23] DEBUG[13490] res_musiconhold.c: SIP/TRUNK_INTER_MAQUINAS-00000005 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 24 16:45:23] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> INVITE sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPjc38375fd-5065-471f-819b-8d24060b4240 Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Contact: "miguel" Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 837 INVITE Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS Supported: replaces, 100rel Content-Type: application/sdp Content-Length: 320 v=0 o=laptop-miguel 3483726774 2 IN IP4 192.168.222.45 s=sflphone c=IN IP4 192.168.222.45 t=0 0 m=audio 29828 RTP/AVP 3 0 8 9 110 111 112 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:110 speex/8000 a=rtpmap:111 speex/16000 a=rtpmap:112 speex/32000 a=sendrecv <-------------> [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 0 [ 38]: INVITE sip:1009@192.168.222.32 SIP/2.0 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPjc38375fd-5065-471f-819b-8d24060b4240 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 4 [ 44]: To: ;tag=as63d8fdea [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 5 [ 47]: Contact: "miguel" [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 6 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 7 [ 16]: CSeq: 837 INVITE [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 8 [ 97]: Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, REGISTER, OPTIONS [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 9 [ 27]: Supported: replaces, 100rel [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 11 [ 21]: Content-Length: 320 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 12 [ 0]: [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 0 [ 3]: v=0 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 1 [ 50]: o=laptop-miguel 3483726774 2 IN IP4 192.168.222.45 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 2 [ 10]: s=sflphone [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.222.45 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 4 [ 5]: t=0 0 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 5 [ 41]: m=audio 29828 RTP/AVP 3 0 8 9 110 111 112 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 6 [ 19]: a=rtpmap:3 GSM/8000 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 9 [ 20]: a=rtpmap:9 G722/8000 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 10 [ 23]: a=rtpmap:110 speex/8000 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 11 [ 24]: a=rtpmap:111 speex/16000 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 12 [ 24]: a=rtpmap:112 speex/32000 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Body 13 [ 10]: a=sendrecv [May 24 16:45:23] VERBOSE[4053] chan_sip.c: --- (12 headers 14 lines) --- [May 24 16:45:23] DEBUG[4053] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Sending to 192.168.222.45 : 8468 (no NAT) [May 24 16:45:23] DEBUG[4053] chan_sip.c: Initializing initreq for method INVITE - callid 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing session-level SDP o=laptop-miguel 3483726774 2 IN IP4 192.168.222.45... UNSUPPORTED. [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing session-level SDP s=sflphone... UNSUPPORTED. [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.222.45... OK. [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found RTP audio format 3 [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found RTP audio format 0 [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found RTP audio format 8 [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found RTP audio format 9 [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found RTP audio format 110 [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found RTP audio format 111 [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found RTP audio format 112 [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found audio description format GSM for ID 3 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found audio description format PCMU for ID 0 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found audio description format PCMA for ID 8 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found audio description format G722 for ID 9 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 110 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:110 speex/8000... OK. [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 111 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:111 speex/16000... OK. [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Found audio description format speex for ID 112 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:112 speex/32000... OK. [May 24 16:45:23] DEBUG[4053] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x1a1e (gsm|ulaw|alaw|g726|speex|g726aal2|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Peer audio RTP is at port 192.168.222.45:29828 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Peer doesn't provide T.38 UDPTL [May 24 16:45:23] DEBUG[4053] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [May 24 16:45:23] DEBUG[4053] chan_sip.c: We have an owner, now see if we need to change this call [May 24 16:45:23] DEBUG[4053] chan_sip.c: Got a SIP re-invite for call 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:23] DEBUG[4053] chan_sip.c: SIP/100-00000004: This call is UP.... [May 24 16:45:23] VERBOSE[4053] chan_sip.c: <--- Transmitting (no NAT) to 192.168.222.45:8468 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.222.45:8468;branch=z9hG4bKPjc38375fd-5065-471f-819b-8d24060b4240;received=192.168.222.45;rport=8468 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 837 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 24 16:45:23] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Setting framing from config on incoming call [May 24 16:45:23] DEBUG[4053] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True [May 24 16:45:23] DEBUG[4053] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Audio is at 192.168.222.32 port 11236 [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Adding codec 0x8 (alaw) to SDP [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [May 24 16:45:23] VERBOSE[4053] chan_sip.c: Adding codec 0x2 (gsm) to SDP [May 24 16:45:23] DEBUG[4053] chan_sip.c: -- Done with adding codecs to SDP [May 24 16:45:23] DEBUG[4053] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [May 24 16:45:23] VERBOSE[4053] chan_sip.c: <--- Reliably Transmitting (no NAT) to 192.168.222.45:8468 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.45:8468;branch=z9hG4bKPjc38375fd-5065-471f-819b-8d24060b4240;received=192.168.222.45;rport=8468 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 837 INVITE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 258 v=0 o=root 16819587 16819589 IN IP4 192.168.222.32 s=Asterisk PBX 1.6.2.8-rc1 c=IN IP4 192.168.222.32 t=0 0 m=audio 11236 RTP/AVP 8 0 3 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [May 24 16:45:23] DEBUG[4053] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2756 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:45:23] DEBUG[13490] rtp.c: Setting the marker bit due to a source update [May 24 16:45:23] VERBOSE[13490] res_musiconhold.c: -- Stopped music on hold on SIP/TRUNK_INTER_MAQUINAS-00000005 [May 24 16:45:23] DEBUG[13490] channel.c: Set channel SIP/TRUNK_INTER_MAQUINAS-00000005 to write format alaw [May 24 16:45:23] DEBUG[13490] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 24 16:45:23] DEBUG[13490] rtp.c: Setting the marker bit due to a source update [May 24 16:45:23] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> ACK sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPjcdefff35-f8be-44d4-9508-12a22866ff7a Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 837 ACK Content-Length: 0 <-------------> [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 0 [ 35]: ACK sip:1009@192.168.222.32 SIP/2.0 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPjcdefff35-f8be-44d4-9508-12a22866ff7a [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 4 [ 44]: To: ;tag=as63d8fdea [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 5 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 6 [ 13]: CSeq: 837 ACK [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 7 [ 18]: Content-Length: 0 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Header 8 [ 0]: [May 24 16:45:23] VERBOSE[4053] chan_sip.c: --- (8 headers 0 lines) --- [May 24 16:45:23] DEBUG[4053] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 16:45:23] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2756 [May 24 16:45:23] DEBUG[4053] chan_sip.c: Stopping retransmission on '74a43ae7-c446-49df-82d2-438d55ebb357' of Response 837: Match Found [May 24 16:45:23] DEBUG[13490] rtp.c: Got RTCP report of 40 bytes [May 24 16:45:23] DEBUG[13490] rtp.c: Forcing Marker bit, because SSRC has changed [May 24 16:45:23] DEBUG[13490] rtp.c: Changing ssrc from 1252471112 to 1058167642 due to a source change [May 24 16:45:27] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:45:30] DEBUG[13490] rtp.c: Got RTCP report of 84 bytes [May 24 16:45:32] DEBUG[13490] rtp.c: Got RTCP report of 64 bytes [May 24 16:45:33] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.45:8468 ---> BYE sip:1009@192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj3a0c0aa3-e7ab-42ab-aa41-7e23682705e5 Max-Forwards: 70 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 838 BYE Content-Length: 0 <-------------> [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 0 [ 35]: BYE sip:1009@192.168.222.32 SIP/2.0 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/UDP 192.168.222.45:8468;rport;branch=z9hG4bKPj3a0c0aa3-e7ab-42ab-aa41-7e23682705e5 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 3 [ 71]: From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 4 [ 44]: To: ;tag=as63d8fdea [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 5 [ 45]: Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 6 [ 13]: CSeq: 838 BYE [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 7 [ 18]: Content-Length: 0 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 8 [ 0]: [May 24 16:45:33] VERBOSE[4053] chan_sip.c: --- (8 headers 0 lines) --- [May 24 16:45:33] DEBUG[4053] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [May 24 16:45:33] DEBUG[4053] chan_sip.c: Initializing initreq for method BYE - callid 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:33] VERBOSE[4053] chan_sip.c: Sending to 192.168.222.45 : 8468 (no NAT) [May 24 16:45:33] DEBUG[4053] chan_sip.c: Setting SIP_ALREADYGONE on dialog 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Received bye, issuing owner hangup [May 24 16:45:33] VERBOSE[4053] chan_sip.c: <--- Transmitting (no NAT) to 192.168.222.45:8468 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.45:8468;branch=z9hG4bKPj3a0c0aa3-e7ab-42ab-aa41-7e23682705e5;received=192.168.222.45;rport=8468 From: ;tag=9d5a146d-08b2-4467-a157-25a1660fc5ae To: ;tag=as63d8fdea Call-ID: 74a43ae7-c446-49df-82d2-438d55ebb357 CSeq: 838 BYE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [May 24 16:45:33] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.222.45:8468 [May 24 16:45:33] DEBUG[13490] channel.c: Didn't get a frame from channel: SIP/100-00000004 [May 24 16:45:33] DEBUG[13490] rtp.c: Setting the marker bit due to a source update [May 24 16:45:33] DEBUG[13490] channel.c: Bridge stops bridging channels SIP/100-00000004 and SIP/TRUNK_INTER_MAQUINAS-00000005 [May 24 16:45:33] VERBOSE[13490] cdr_pgsql.c: > [INSERT INTO cdr ("calldate","clid","src","dst","dcontext","channel","dstchannel","lastapp","lastdata","duration","billsec","disposition","amaflags","uniqueid") VALUES ('2010-05-24 16:44:37','100','100','1009','default','SIP/100-00000004','SIP/TRUNK_INTER_MAQUINAS-00000005','Dial','SIP/TRUNK_INTER_MAQUINAS/1004',56,56,'ANSWERED',3,'1274737477.5')] [May 24 16:45:33] DEBUG[13490] cdr_pgsql.c: inserting a CDR record. [May 24 16:45:33] DEBUG[13490] channel.c: Hanging up channel 'SIP/TRUNK_INTER_MAQUINAS-00000005' [May 24 16:45:33] DEBUG[13490] chan_sip.c: Hangup call SIP/TRUNK_INTER_MAQUINAS-00000005, SIP callid 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:45:33] VERBOSE[13490] chan_sip.c: Scheduling destruction of SIP dialog '50254fb032d586fe3a6d81987db9f31b@192.168.222.32' in 6400 ms (Method: INVITE) [May 24 16:45:33] DEBUG[13490] chan_sip.c: Session timer stopped: -1 - 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:45:33] DEBUG[13490] chan_sip.c: Strict routing enforced for session 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:45:33] VERBOSE[13490] chan_sip.c: set_destination: Parsing for address/port to send to [May 24 16:45:33] VERBOSE[13490] chan_sip.c: set_destination: set destination to 192.168.222.33, port 5060 [May 24 16:45:33] VERBOSE[13490] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.222.33:5060: BYE sip:1004@192.168.222.33 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7ab6b6d2;rport Max-Forwards: 70 From: "100" ;tag=as64cb91d5 To: ;tag=as2b2bee60 Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 104 BYE User-Agent: Asterisk PBX 1.6.2.8-rc1 Authorization: Digest username="TRUNK_INTER_MAQUINAS", realm="asterisk", algorithm=MD5, uri="sip:1004@192.168.222.33", nonce="774515e4", response="c52265ec0c9bebcbc174d294a7edb372" X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [May 24 16:45:33] DEBUG[13490] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2759 [May 24 16:45:33] DEBUG[13490] chan_sip.c: Trying to put 'BYE sip:100' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:45:33] DEBUG[13490] rtp.c: Channel '' has no RTP, not doing anything [May 24 16:45:33] DEBUG[13490] app_dial.c: Exiting with DIALSTATUS=ANSWER. [May 24 16:45:33] DEBUG[13490] pbx.c: Spawn extension (default,1009,1) exited non-zero on 'SIP/100-00000004' [May 24 16:45:33] VERBOSE[13490] pbx.c: == Spawn extension (default, 1009, 1) exited non-zero on 'SIP/100-00000004' [May 24 16:45:33] DEBUG[13490] channel.c: Soft-Hanging up channel 'SIP/100-00000004' [May 24 16:45:33] DEBUG[13490] channel.c: Hanging up channel 'SIP/100-00000004' [May 24 16:45:33] DEBUG[13490] chan_sip.c: Hangup call SIP/100-00000004, SIP callid 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:33] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.33:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7ab6b6d2;received=192.168.222.32;rport=5060 From: "100" ;tag=as64cb91d5 To: ;tag=as2b2bee60 Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 CSeq: 104 BYE Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <-------------> [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK7ab6b6d2;received=192.168.222.32;rport=5060 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 2 [ 51]: From: "100" ;tag=as64cb91d5 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 3 [ 44]: To: ;tag=as2b2bee60 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 4 [ 56]: Call-ID: 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 5 [ 13]: CSeq: 104 BYE [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 6 [ 32]: Server: Asterisk PBX 1.6.2.8-rc1 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Header 10 [ 0]: [May 24 16:45:33] VERBOSE[4053] chan_sip.c: --- (10 headers 0 lines) --- [May 24 16:45:33] DEBUG[4053] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2759 [May 24 16:45:33] DEBUG[4053] chan_sip.c: Stopping retransmission on '50254fb032d586fe3a6d81987db9f31b@192.168.222.32' of Request 104: Match Found [May 24 16:45:33] DEBUG[4053] chan_sip.c: Destroying SIP dialog 74a43ae7-c446-49df-82d2-438d55ebb357 [May 24 16:45:33] VERBOSE[4053] chan_sip.c: Really destroying SIP dialog '74a43ae7-c446-49df-82d2-438d55ebb357' Method: BYE [May 24 16:45:33] DEBUG[4053] chan_sip.c: Destroying SIP dialog 50254fb032d586fe3a6d81987db9f31b@192.168.222.32 [May 24 16:45:33] VERBOSE[4053] chan_sip.c: Really destroying SIP dialog '50254fb032d586fe3a6d81987db9f31b@192.168.222.32' Method: INVITE [May 24 16:45:33] DEBUG[4028] devicestate.c: No provider found, checking channel drivers for SIP - TRUNK_INTER_MAQUINAS [May 24 16:45:33] DEBUG[4028] chan_sip.c: Checking device state for peer TRUNK_INTER_MAQUINAS [May 24 16:45:33] DEBUG[4028] devicestate.c: Changing state for SIP/TRUNK_INTER_MAQUINAS - state 1 (Not in use) [May 24 16:45:33] DEBUG[4028] devicestate.c: device 'SIP/TRUNK_INTER_MAQUINAS' state '1' [May 24 16:45:33] DEBUG[4028] devicestate.c: No provider found, checking channel drivers for SIP - 100 [May 24 16:45:33] DEBUG[4028] chan_sip.c: Checking device state for peer 100 [May 24 16:45:33] DEBUG[4028] devicestate.c: Changing state for SIP/100 - state 1 (Not in use) [May 24 16:45:33] DEBUG[4028] devicestate.c: device 'SIP/100' state '1' [May 24 16:45:33] DEBUG[4056] app_queue.c: Device 'SIP/TRUNK_INTER_MAQUINAS' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 24 16:45:33] DEBUG[4056] app_queue.c: Device 'SIP/100' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 24 16:45:48] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.33:5060 ---> OPTIONS sip:192.168.222.32 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.33:5060;branch=z9hG4bK27eddb88;rport Max-Forwards: 70 From: "asterisk" ;tag=as06fb6dd7 To: Contact: Call-ID: 0045ffb93f07bee6617ad95d33c612e5@192.168.222.33 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.8-rc1 Date: Mon, 24 May 2010 21:45:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <-------------> [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 0 [ 34]: OPTIONS sip:192.168.222.32 SIP/2.0 [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.222.33:5060;branch=z9hG4bK27eddb88;rport [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as06fb6dd7 [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 4 [ 24]: To: [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 5 [ 38]: Contact: [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 6 [ 56]: Call-ID: 0045ffb93f07bee6617ad95d33c612e5@192.168.222.33 [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.6.2.8-rc1 [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 9 [ 35]: Date: Mon, 24 May 2010 21:45:48 GMT [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 24 16:45:48] DEBUG[4053] chan_sip.c: Header 13 [ 0]: [May 24 16:45:48] VERBOSE[4053] chan_sip.c: --- (13 headers 0 lines) --- [May 24 16:45:48] DEBUG[4053] acl.c: Found IP address for this socket [May 24 16:45:48] DEBUG[4053] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.222.32:5060 [May 24 16:45:48] DEBUG[4053] chan_sip.c: Allocating new SIP dialog for 0045ffb93f07bee6617ad95d33c612e5@192.168.222.33 - OPTIONS (No RTP) [May 24 16:45:48] DEBUG[4053] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [May 24 16:45:48] VERBOSE[4053] chan_sip.c: Looking for s in default (domain 192.168.222.32) [May 24 16:45:48] VERBOSE[4053] chan_sip.c: <--- Transmitting (no NAT) to 192.168.222.33:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.33:5060;branch=z9hG4bK27eddb88;received=192.168.222.33;rport=5060 From: "asterisk" ;tag=as06fb6dd7 To: ;tag=as4719fa2c Call-ID: 0045ffb93f07bee6617ad95d33c612e5@192.168.222.33 CSeq: 102 OPTIONS Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> [May 24 16:45:48] DEBUG[4053] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.222.33:5060 [May 24 16:45:48] VERBOSE[4053] chan_sip.c: Scheduling destruction of SIP dialog '0045ffb93f07bee6617ad95d33c612e5@192.168.222.33' in 32000 ms (Method: OPTIONS) [May 24 16:46:01] VERBOSE[4053] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.222.33:5060: OPTIONS sip:192.168.222.33 SIP/2.0 Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK21827484;rport Max-Forwards: 70 From: "asterisk" ;tag=as6b31dce4 To: Contact: Call-ID: 7645c27922a477d9684751537a934617@192.168.222.32 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.8-rc1 Date: Mon, 24 May 2010 21:46:01 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [May 24 16:46:01] VERBOSE[4053] chan_sip.c: <--- SIP read from UDP:192.168.222.33:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.222.32:5060;branch=z9hG4bK21827484;received=192.168.222.32;rport=5060 From: "asterisk" ;tag=as6b31dce4 To: ;tag=as49e48a7a Call-ID: 7645c27922a477d9684751537a934617@192.168.222.32 CSeq: 102 OPTIONS Server: Asterisk PBX 1.6.2.8-rc1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <-------------> [May 24 16:46:01] VERBOSE[4053] chan_sip.c: --- (12 headers 0 lines) --- [May 24 16:46:01] VERBOSE[4053] chan_sip.c: Really destroying SIP dialog '7645c27922a477d9684751537a934617@192.168.222.32' Method: OPTIONS