-- Attempting call on SIP/800@aretha.navynet.it for s@faxout:1 (Retry 1)
Nov 8 12:38:14 DEBUG[58643]: chan_sip.c:4150 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
Nov 8 12:38:14 DEBUG[58643]: acl.c:218 opbx_apply_ha: ##### Testing 195.110.100.99 with 192.168.3.0. Result 1
Nov 8 12:38:14 DEBUG[58643]: chan_sip.c:1249 opbx_sip_ouraddrfor: Target address 195.110.100.99 is not local, substituting externip with 83.132.175.61 and enabling stun
Setting up to call extension '800' at 'aretha.navynet.it'
Nov 8 12:38:14 DEBUG[58643]: chan_sip.c:2759 sip_call: Outgoing Call for 800
Nov 8 12:38:14 DEBUG[58643]: chan_sip.c:2767 sip_call: Our T38 capability (12048), joint T38 capability (12048)
We're at 83.132.175.61 port 15672
Adding codec 0x2 (gsm) to SDP
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
13 headers, 10 lines
Nov 8 12:38:14 DEBUG[58643]: chan_sip.c:1920 send_request: This call request 660f4d0c79a5c7ff2ec2411e49b2dd02@83.132.175.61 seqno 102 really needs STUN - sched 0
** STUN Packet SENT 867512719 867512719
Nov 8 12:38:14 DEBUG[58643]: chan_sip.c:1939 send_request: Setting NAT on RTP to 1
Nov 8 12:38:14 DEBUG[58643]: udp.c:293 udp_socket_set_nat: Sending stun request on this UDP channel (port 15672) cause NAT is on
** STUN Packet SENT 1571754930 1571754930
Nov 8 12:38:14 DEBUG[58643]: udp.c:293 udp_socket_set_nat: Sending stun request on this UDP channel (port 15673) cause NAT is on
** STUN Packet SENT 1847809941 1847809941
Nov 8 12:38:14 DEBUG[58643]: chan_sip.c:1954 send_request: ** Sent STUN packet for request 867512719
Nov 8 12:38:14 DEBUG[58643]: timer.c:196 opbx_timer_start: Timer 0x8281218 set to 0.1000000 repeat 0.0
Nov 8 12:38:15 DEBUG[58643]: udp.c:405 udp_socket_recvfrom: Checking if payload it is a stun RESPONSE
STUN Packet, msg Binding Response (0101), length: 68
Found STUN Attribute Mapped Address (0001), length 8
STUN: Mapped address is 83.132.175.61
STUN: Mapped port is 63420
Found STUN Attribute Source Address (0004), length 8
Found STUN Attribute Changed Address (0005), length 8
Ignoring STUN attribute Changed Address (0005), length 8
Found STUN Attribute Non-RFC3489 Attribute (8020), length 8
Ignoring STUN attribute Non-RFC3489 Attribute (8020), length 8
Found STUN Attribute Non-RFC3489 Attribute (8022), length 16
Ignoring STUN attribute Non-RFC3489 Attribute (8022), length 16
** STUN Bind Response
** STUN request not matching. ID: 1847809941 done at: 1162989494 gotresponse 0:
** Found response in request queue. ID: 1571754930 done at: 1162989494 gotresponse: 0
** STUN request not matching. ID: 867512719 done at: 1162989494 gotresponse 0:
** STUN request not matching. ID: 1800790002 done at: 1162989453 gotresponse 1:
** STUN request not matching. ID: 451976164 done at: 1162989422 gotresponse 1:
Nov 8 12:38:15 DEBUG[58643]: udp.c:411 udp_socket_recvfrom: Got STUN bind response
** Trying to lookup for removal stun queue 1571754930
** Found: request in removal stun queue 1571754930
Nov 8 12:38:15 DEBUG[58643]: udp.c:405 udp_socket_recvfrom: Checking if payload it is a stun RESPONSE
STUN Packet, msg Binding Response (0101), length: 68
Found STUN Attribute Mapped Address (0001), length 8
STUN: Mapped address is 83.132.175.61
STUN: Mapped port is 59270
Found STUN Attribute Source Address (0004), length 8
Found STUN Attribute Changed Address (0005), length 8
Ignoring STUN attribute Changed Address (0005), length 8
Found STUN Attribute Non-RFC3489 Attribute (8020), length 8
Ignoring STUN attribute Non-RFC3489 Attribute (8020), length 8
Found STUN Attribute Non-RFC3489 Attribute (8022), length 16
Ignoring STUN attribute Non-RFC3489 Attribute (8022), length 16
** STUN Bind Response
** Found response in request queue. ID: 1847809941 done at: 1162989494 gotresponse: 0
** STUN request not matching. ID: 867512719 done at: 1162989494 gotresponse 0:
** STUN request not matching. ID: 1800790002 done at: 1162989453 gotresponse 1:
** STUN request not matching. ID: 451976164 done at: 1162989422 gotresponse 1:
Nov 8 12:38:15 DEBUG[58643]: udp.c:411 udp_socket_recvfrom: Got STUN bind response
** Trying to lookup for removal stun queue 1847809941
** Found: request in removal stun queue 1847809941
<-- SIP read from 64.69.76.23:3478:
STUN Packet, msg Binding Response (0101), length: 68
Found STUN Attribute Mapped Address (0001), length 8
STUN: Mapped address is 83.132.175.61
STUN: Mapped port is 63581
Found STUN Attribute Source Address (0004), length 8
Found STUN Attribute Changed Address (0005), length 8
Ignoring STUN attribute Changed Address (0005), length 8
Found STUN Attribute Non-RFC3489 Attribute (8020), length 8
Ignoring STUN attribute Non-RFC3489 Attribute (8020), length 8
Found STUN Attribute Non-RFC3489 Attribute (8022), length 16
Ignoring STUN attribute Non-RFC3489 Attribute (8022), length 16
** STUN Bind Response
** Found response in request queue. ID: 867512719 done at: 1162989494 gotresponse: 0
** STUN request not matching. ID: 1800790002 done at: 1162989453 gotresponse 1:
** STUN request not matching. ID: 451976164 done at: 1162989422 gotresponse 1:
Nov 8 12:38:15 DEBUG[58643]: chan_sip.c:14005 sipsock_read: Got STUN bind response on SIP channel.
Nov 8 12:38:45 DEBUG[58643]: cdr_sqlite3.c:167 sqlite_log: CDR SQLITE3 SQL [INSERT INTO cdr (clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata, start,answer,end,duration,billsec,disposition,amaflags, accountcode) VALUES ('', '', 's', 'faxout', 'SIP/aretha.navynet.it-04c0', '', 'Dial', 'SIP/800@aretha.navynet.it', '2006-11-08 12:38:45', '1970-01-01 01:00:00', '2006-11-08 12:38:45', 0, 0, 8, 3, '')]
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 's'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'faxout'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'SIP/aretha.navynet.it-04c0'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'Dial'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'SIP/800@aretha.navynet.it'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '2006-11-08 12:38:45'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '2006-11-08 12:38:45'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '0'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '0'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'FAILED'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '1162989494.2'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: channel.c:1108 opbx_hangup: Hanging up channel 'SIP/aretha.navynet.it-04c0'
Nov 8 12:38:45 DEBUG[58643]: chan_sip.c:3141 sip_hangup: Hangup call SIP/aretha.navynet.it-04c0, SIP callid 660f4d0c79a5c7ff2ec2411e49b2dd02@83.132.175.61)
Nov 8 12:38:45 DEBUG[58643]: chan_sip.c:3150 sip_hangup: update_call_counter(800) - decrement call limit counter
Nov 8 12:38:45 DEBUG[58643]: chan_sip.c:1920 send_request: This call request 660f4d0c79a5c7ff2ec2411e49b2dd02@83.132.175.61 seqno 102 really needs STUN - sched 4
** STUN Packet SENT 101969219 101969219
Nov 8 12:38:45 DEBUG[58643]: chan_sip.c:1954 send_request: ** Sent STUN packet for request 101969219
Nov 8 12:38:45 DEBUG[58643]: timer.c:196 opbx_timer_start: Timer 0x8281218 set to 0.1000000 repeat 0.0
Scheduling destruction of call '660f4d0c79a5c7ff2ec2411e49b2dd02@83.132.175.61' in 15000 ms
Nov 8 12:38:45 DEBUG[58643]: timer.c:196 opbx_timer_start: Timer 0x8281218 set to 0.1000000 repeat 0.0
Nov 8 12:38:45 DEBUG[58643]: channel.c:1122 opbx_hangup: Generator : deactivate after channel unlock (hangup function)
Nov 8 12:38:45 DEBUG[58643]: generator.c:124 opbx_generator_deactivate: Trying to deactivate generator in SIP/aretha.navynet.it-04c0
Nov 8 12:38:45 DEBUG[58643]: generator.c:151 opbx_generator_deactivate: Generator on SIP/aretha.navynet.it-04c0 stopped after 0 iterations
Nov 8 12:38:45 DEBUG[58643]: cdr_sqlite3.c:167 sqlite_log: CDR SQLITE3 SQL [INSERT INTO cdr (clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata, start,answer,end,duration,billsec,disposition,amaflags, accountcode) VALUES ('', '', 's', 'default', '**Unkown**', '', '', '', '2006-11-08 12:38:45', '1970-01-01 01:00:00', '2006-11-08 12:38:45', 0, 0, 8, 3, '')]
Nov 8 12:38:45 DEBUG[58643]: app_queue.c:480 changethread: Device 'SIP/aretha.navynet.it' changed to state '1' (Not in use)
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 's'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'default'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '**Unkown**'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '2006-11-08 12:38:45'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '2006-11-08 12:38:45'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '0'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '0'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'FAILED'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '1162989525.3'
Nov 8 12:38:45 DEBUG[58643]: pbx.c:1673 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 8 12:38:45 NOTICE[58643]: pbx_spool.c:269 attempt_thread: Call failed to go through, reason 0
<-- SIP read from 64.69.76.23:3478:
STUN Packet, msg Binding Response (0101), length: 68
Found STUN Attribute Mapped Address (0001), length 8
STUN: Mapped address is 83.132.175.61
STUN: Mapped port is 63581
Found STUN Attribute Source Address (0004), length 8
Found STUN Attribute Changed Address (0005), length 8
Ignoring STUN attribute Changed Address (0005), length 8
Found STUN Attribute Non-RFC3489 Attribute (8020), length 8
Ignoring STUN attribute Non-RFC3489 Attribute (8020), length 8
Found STUN Attribute Non-RFC3489 Attribute (8022), length 16
Ignoring STUN attribute Non-RFC3489 Attribute (8022), length 16
** STUN Bind Response
** Found response in request queue. ID: 101969219 done at: 1162989525 gotresponse: 0
** STUN request not matching. ID: 867512719 done at: 1162989494 gotresponse 1:
** STUN request not matching. ID: 1800790002 done at: 1162989453 gotresponse 1:
** STUN request not matching. ID: 451976164 done at: 1162989422 gotresponse 1:
Nov 8 12:38:45 DEBUG[58643]: chan_sip.c:14005 sipsock_read: Got STUN bind response on SIP channel.