Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received INVITE (5) - Command in SIP INVITE
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1033 parse_sip_options: * SIP extension value: 39 for call 91943640547200610136@172.17.1.10
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:7155 check_user_full: Setting NAT on RTP to 0
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:7159 check_user_full: Setting NAT on VRTP to 0
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received ACK (6) - Command in SIP ACK
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '91943640547200610136@172.17.1.10' of Response 1: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received INVITE (5) - Command in SIP INVITE
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:7155 check_user_full: Setting NAT on RTP to 0
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:7159 check_user_full: Setting NAT on VRTP to 0
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:10497 handle_request_invite: Checking SIP call limits for device 511
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:2209 update_call_counter: Updating call counter for incoming call
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:6137 build_route: build_route: Contact hop: <sip:511@172.17.1.10>
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 511
Jul  4 12:13:06 DEBUG[16036]: devicestate.c:187 do_state_change: Changing state for SIP/511 - state 2 (In use)
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 511
Jul  4 12:13:06 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'Goto'
    -- Executing Goto("SIP/511-54ae", "test|100|1") in new stack
    -- Goto (test,100,1)
Jul  4 12:13:06 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'Dial'
    -- Executing Dial("SIP/511-54ae", "SIP/537") in new stack
Jul  4 12:13:06 DEBUG[16322]: chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
Jul  4 12:13:06 DEBUG[16322]: chan_sip.c:1874 create_addr_from_peer: Setting NAT on RTP to 0
Jul  4 12:13:06 DEBUG[16322]: chan_sip.c:1878 create_addr_from_peer: Setting NAT on VRTP to 0
Jul  4 12:13:06 DEBUG[16322]: acl.c:211 ast_apply_ha: ##### Testing 172.17.5.37 with 192.168.1.0
Jul  4 12:13:06 DEBUG[16322]: acl.c:211 ast_apply_ha: ##### Testing 172.17.5.37 with 172.17.0.0
Jul  4 12:13:06 DEBUG[16322]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-test-100-1.
Jul  4 12:13:06 DEBUG[16322]: channel.c:2823 ast_channel_inherit_variables: Not copying variable STACK-internal-100-1.
Jul  4 12:13:06 DEBUG[16322]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPCALLID.
Jul  4 12:13:06 DEBUG[16322]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT.
Jul  4 12:13:06 DEBUG[16322]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPDOMAIN.
Jul  4 12:13:06 DEBUG[16322]: channel.c:2823 ast_channel_inherit_variables: Not copying variable SIPURI.
Jul  4 12:13:06 DEBUG[16322]: chan_sip.c:2068 sip_call: Outgoing Call for 537
Jul  4 12:13:06 DEBUG[16322]: chan_sip.c:2209 update_call_counter: Updating call counter for outgoing call
    -- Called 537
Jul  4 12:13:06 DEBUG[16322]: channel.c:2350 set_format: Set channel SIP/537-9c0c to read format alaw
Jul  4 12:13:06 DEBUG[16322]: channel.c:2350 set_format: Set channel SIP/511-54ae to write format alaw
Jul  4 12:13:06 DEBUG[16322]: channel.c:2350 set_format: Set channel SIP/511-54ae to read format alaw
Jul  4 12:13:06 DEBUG[16322]: channel.c:2350 set_format: Set channel SIP/537-9c0c to write format alaw
Jul  4 12:13:06 DEBUG[16323]: app_queue.c:523 changethread: Device 'SIP/511' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1454 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl' Request 102: Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:9584 handle_response_invite: SIP response 180 to standard invite
    -- SIP/537-9c0c is ringing
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
Jul  4 12:13:06 DEBUG[16036]: devicestate.c:187 do_state_change: Changing state for SIP/537 - state 6 (Ringing)
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Ringing for Notify User 584
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Ringing for Notify User 585
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Ringing for Notify User 516
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Ringing for Notify User 517
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Ringing for Notify User 598
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Ringing for Notify User 558
Jul  4 12:13:06 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Ringing for Notify User 547
Jul  4 12:13:06 DEBUG[16324]: app_queue.c:523 changethread: Device 'SIP/537' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700c8647-xahkiv25v6d5@snom360-000413231BA1' of Request 112: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d3345-l80dimw9exzw@snom360-000413231A8A' of Request 108: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d4e20-crtrmn89n8ul@snom360-0004132306B3' of Request 112: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c267009be6e-tc2zwxmzjwva@snom320-0004132429F1' of Request 109: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c267009afc8-dl3cwilu2bzl@snom320-0004132445FC' of Request 112: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700bd467-azb40s7uwy3a@snom320-000413240720' of Request 112: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700caae6-py9zspt86vt5@snom190' of Request 112: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 517 context internal for peer 537
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 517
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 517
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700c7a12-78a17qn07grp@snom360-00041323068A' of Request 105: Match Found
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 516 context internal for peer 537
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 516
Jul  4 12:13:06 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 516
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700c72bf-l6cjsyaffl8h@snom360-00041323068A' of Request 105: Match Found
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 584 context internal for peer 537
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 584
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 584
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700c88b8-bsly8o2x8792@snom360-00041323068A' of Request 105: Match Found
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 547 context internal for peer 537
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 547
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 547
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:1454 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl' Request 102: Found
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:9584 handle_response_invite: SIP response 180 to standard invite
    -- SIP/537-9c0c is ringing
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700c8165-f5i2592wj4pk@snom360-00041323068A' of Request 105: Match Found
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 585 context internal for peer 537
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 585
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 585
Jul  4 12:13:07 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700c900b-gwiidqqnc0gz@snom360-00041323068A' of Request 105: Match Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1454 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl' Request 102: Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:9584 handle_response_invite: SIP response 180 to standard invite
    -- SIP/537-9c0c is ringing
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jul  4 12:13:08 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 194.221.62.200 with 192.168.1.0
Jul  4 12:13:08 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 194.221.62.200 with 172.17.0.0
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1118 ast_sip_ouraddrfor: Target address 194.221.62.200 is not local, substituting externip
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jul  4 12:13:08 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 194.221.62.201 with 192.168.1.0
Jul  4 12:13:08 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 194.221.62.201 with 172.17.0.0
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1118 ast_sip_ouraddrfor: Target address 194.221.62.201 is not local, substituting externip
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jul  4 12:13:08 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 194.120.0.200 with 192.168.1.0
Jul  4 12:13:08 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 194.120.0.200 with 172.17.0.0
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1118 ast_sip_ouraddrfor: Target address 194.120.0.200 is not local, substituting externip
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jul  4 12:13:08 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 194.120.0.201 with 192.168.1.0
Jul  4 12:13:08 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 194.120.0.201 with 172.17.0.0
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1118 ast_sip_ouraddrfor: Target address 194.120.0.201 is not local, substituting externip
Jul  4 12:13:08 DEBUG[16322]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1379 __sip_ack: Acked pending invite 102
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl' of Request 102: Match Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:9584 handle_response_invite: SIP response 200 to standard invite
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:6137 build_route: build_route: Contact hop: <sip:537@172.17.5.37:5060;line=rw9bi3ww>;flow-id=1
    -- SIP/537-9c0c answered SIP/511-54ae
Jul  4 12:13:08 DEBUG[16322]: channel.c:2350 set_format: Set channel SIP/511-54ae to read format alaw
Jul  4 12:13:08 DEBUG[16322]: channel.c:2350 set_format: Set channel SIP/537-9c0c to write format alaw
Jul  4 12:13:08 DEBUG[16322]: channel.c:2350 set_format: Set channel SIP/537-9c0c to read format alaw
Jul  4 12:13:08 DEBUG[16322]: channel.c:2350 set_format: Set channel SIP/511-54ae to write format alaw
Jul  4 12:13:08 DEBUG[16322]: chan_sip.c:2540 sip_answer: sip_answer(SIP/511-54ae)
    -- Attempting native bridge of SIP/511-54ae and SIP/537-9c0c
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
Jul  4 12:13:08 DEBUG[16036]: devicestate.c:187 do_state_change: Changing state for SIP/537 - state 2 (In use)
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state InUse for Notify User 584
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state InUse for Notify User 585
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state InUse for Notify User 516
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state InUse for Notify User 517
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state InUse for Notify User 598
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state InUse for Notify User 558
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state InUse for Notify User 547
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 511
Jul  4 12:13:08 DEBUG[16036]: devicestate.c:187 do_state_change: Changing state for SIP/511 - state 2 (In use)
Jul  4 12:13:08 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 511
Jul  4 12:13:08 DEBUG[16325]: app_queue.c:523 changethread: Device 'SIP/537' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jul  4 12:13:08 DEBUG[16326]: app_queue.c:523 changethread: Device 'SIP/511' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d4e20-crtrmn89n8ul@snom360-0004132306B3' of Request 113: Match Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700c8647-xahkiv25v6d5@snom360-000413231BA1' of Request 113: Match Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c267009afc8-dl3cwilu2bzl@snom320-0004132445FC' of Request 113: Match Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received ACK (6) - Command in SIP ACK
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '91943640547200610136@172.17.1.10' of Response 2: Match Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700bd467-azb40s7uwy3a@snom320-000413240720' of Request 113: Match Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c267009be6e-tc2zwxmzjwva@snom320-0004132429F1' of Request 110: Match Found
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d3345-l80dimw9exzw@snom360-000413231A8A' of Request 109: Match Found
Jul  4 12:13:08 DEBUG[16322]: rtp.c:1352 ast_rtp_write: Ooh, format changed from unknown to alaw
Jul  4 12:13:08 DEBUG[16322]: rtp.c:411 ast_rtcp_read: Got RTCP report of 44 bytes
Jul  4 12:13:08 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700caae6-py9zspt86vt5@snom190' of Request 113: Match Found
Jul  4 12:13:08 DEBUG[16322]: rtp.c:1352 ast_rtp_write: Ooh, format changed from unknown to alaw
Jul  4 12:13:09 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 172.17.5.85 with 192.168.1.0
Jul  4 12:13:09 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 172.17.5.85 with 172.17.0.0
Jul  4 12:13:09 DEBUG[16043]: chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for 3c2bbde8d1f6-vmcjainc40f2@snom320-0004132429F1 - REGISTER (No RTP)
Jul  4 12:13:09 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
Jul  4 12:13:09 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER
Jul  4 12:13:09 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 585
Jul  4 12:13:09 DEBUG[16036]: devicestate.c:187 do_state_change: Changing state for SIP/585 - state 1 (Not in use)
Jul  4 12:13:09 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 585
Jul  4 12:13:09 DEBUG[16327]: app_queue.c:523 changethread: Device 'SIP/585' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Jul  4 12:13:09 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl' of Request 102: Match Not Found
Jul  4 12:13:09 DEBUG[16043]: chan_sip.c:9582 handle_response_invite: SIP response 200 to RE-invite on outgoing call 302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl
Jul  4 12:13:09 DEBUG[16043]: chan_sip.c:6080 build_route: build_route: Retaining previous route: <sip:537@172.17.5.37:5060;line=rw9bi3ww>
Jul  4 12:13:10 DEBUG[16322]: rtp.c:411 ast_rtcp_read: Got RTCP report of 80 bytes
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received BYE (8) - Command in SIP BYE
Jul  4 12:13:10 DEBUG[16322]: channel.c:3275 ast_generic_bridge: Didn't get a frame from channel: SIP/511-54ae
Jul  4 12:13:10 DEBUG[16322]: channel.c:3550 ast_channel_bridge: Bridge stops bridging channels SIP/511-54ae and SIP/537-9c0c
Jul  4 12:13:10 DEBUG[16322]: channel.c:1323 ast_hangup: Hanging up channel 'SIP/537-9c0c'
Jul  4 12:13:10 DEBUG[16322]: chan_sip.c:2418 sip_hangup: Hangup call SIP/537-9c0c, SIP callid 302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl)
Jul  4 12:13:10 DEBUG[16322]: chan_sip.c:2426 sip_hangup: update_call_counter(537) - decrement call limit counter
Jul  4 12:13:10 DEBUG[16322]: chan_sip.c:2209 update_call_counter: Updating call counter for outgoing call
Jul  4 12:13:10 DEBUG[16322]: app_dial.c:1628 dial_exec_full: Exiting with DIALSTATUS=ANSWER.
Jul  4 12:13:10 DEBUG[16322]: pbx.c:2316 __ast_pbx_run: Spawn extension (test,100,1) exited non-zero on 'SIP/511-54ae'
Jul  4 12:13:10 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'Macro'
    -- Executing Macro("SIP/511-54ae", "enddial|ANSWER") in new stack
Jul  4 12:13:10 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'NoOp'
    -- Executing NoOp("SIP/511-54ae", "Macro-enddial: ANSWER") in new stack
Jul  4 12:13:10 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'NoOp'
    -- Executing NoOp("SIP/511-54ae", "Evaluate the call after hangup") in new stack
Jul  4 12:13:10 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'Macro'
    -- Executing Macro("SIP/511-54ae", "test") in new stack
Jul  4 12:13:10 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'NoOp'
    -- Executing NoOp("SIP/511-54ae", "Test macro Line1") in new stack
Jul  4 12:13:10 DEBUG[16322]: app_macro.c:245 macro_exec: Extension s, priority 1 returned normally even though call was hung up
Jul  4 12:13:10 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'NoOp'
    -- Executing NoOp("SIP/511-54ae", "end macro enddial") in new stack
Jul  4 12:13:10 DEBUG[16322]: pbx.c:1677 pbx_extension_helper: Launching 'Hangup'
    -- Executing Hangup("SIP/511-54ae", "") in new stack
Jul  4 12:13:10 DEBUG[16322]: pbx.c:2454 __ast_pbx_run: Spawn extension (test,h,2) exited non-zero on 'SIP/511-54ae'
Jul  4 12:13:10 DEBUG[16322]: cdr.c:992 ast_cdr_detach: Dropping CDR !
Jul  4 12:13:10 DEBUG[16322]: channel.c:1323 ast_hangup: Hanging up channel 'SIP/511-54ae'
Jul  4 12:13:10 DEBUG[16322]: chan_sip.c:2418 sip_hangup: Hangup call SIP/511-54ae, SIP callid 91943640547200610136@172.17.1.10)
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
Jul  4 12:13:10 DEBUG[16036]: devicestate.c:187 do_state_change: Changing state for SIP/537 - state 1 (Not in use)
Jul  4 12:13:10 DEBUG[16322]: chan_sip.c:2426 sip_hangup: update_call_counter(511) - decrement call limit counter
Jul  4 12:13:10 DEBUG[16322]: chan_sip.c:2209 update_call_counter: Updating call counter for incoming call
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Idle for Notify User 584
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Idle for Notify User 585
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Idle for Notify User 516
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Idle for Notify User 517
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Idle for Notify User 598
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Idle for Notify User 558
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
 Extension Changed 537 new state Idle for Notify User 547
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 511
Jul  4 12:13:10 DEBUG[16036]: devicestate.c:187 do_state_change: Changing state for SIP/511 - state 1 (Not in use)
Jul  4 12:13:10 DEBUG[16036]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 511
Jul  4 12:13:10 DEBUG[16328]: app_queue.c:523 changethread: Device 'SIP/537' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Jul  4 12:13:10 DEBUG[16329]: app_queue.c:523 changethread: Device 'SIP/511' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700c8647-xahkiv25v6d5@snom360-000413231BA1' of Request 114: Match Found
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1198 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 28 ms (t1 14 ms (Retrans id #1713))
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700bd467-azb40s7uwy3a@snom320-000413240720' of Request 114: Match Found
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c267009be6e-tc2zwxmzjwva@snom320-0004132429F1' of Request 111: Match Found
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d3345-l80dimw9exzw@snom360-000413231A8A' of Request 110: Match Found
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d4e20-crtrmn89n8ul@snom360-0004132306B3' of Request 114: Match Found
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c267009afc8-dl3cwilu2bzl@snom320-0004132445FC' of Request 114: Match Found
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1198 retrans_pkt: ** SIP timers: Rescheduling retransmission 3 to 56 ms (t1 14 ms (Retrans id #1713))
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl' of Request 103: Match Found
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700caae6-py9zspt86vt5@snom190' of Request 114: Match Found
Jul  4 12:13:10 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 172.17.5.37 with 192.168.1.0
Jul  4 12:13:10 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 172.17.5.37 with 172.17.0.0
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for 302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl - SIP/2.0 (No RTP)
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:11113 handle_request: That's odd...  Got a response on a call we dont know about. Cseq 103 Cmd SIP/2.0
Jul  4 12:13:10 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 172.17.5.37 with 192.168.1.0
Jul  4 12:13:10 DEBUG[16043]: acl.c:211 ast_apply_ha: ##### Testing 172.17.5.37 with 172.17.0.0
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:3147 sip_alloc: Allocating new SIP dialog for 302cbe9232143e5676145a310a9c7a6a@pbx.trends.nl - SIP/2.0 (No RTP)
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:11113 handle_request: That's odd...  Got a response on a call we dont know about. Cseq 103 Cmd SIP/2.0
Jul  4 12:13:10 DEBUG[16043]: chan_sip.c:1323 __sip_autodestruct: Auto destroying call '3c26700a8647-lgo4jc3q2kbq@snom190'
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:1323 __sip_autodestruct: Auto destroying call '102410-900408185@pbx.trends.nl'
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 516 context internal for peer 584
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 516
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 516
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d249f-apcq5ua0gype@snom360-000413231A8A' of Request 105: Match Found
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 537 context internal for peer 584
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 537
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 547 context internal for peer 584
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 547
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 547
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d3345-l80dimw9exzw@snom360-000413231A8A' of Request 111: Match Found
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d3a98-qs86lm3l3nwx@snom360-000413231A8A' of Request 105: Match Found
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 585 context internal for peer 584
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 585
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 585
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d41eb-3s86dbdatyyo@snom360-000413231A8A' of Request 105: Match Found
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11143 handle_request: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:10988 handle_request_subscribe: Adding subscription for extension 517 context internal for peer 584
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 517
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:11674 sip_devicestate: Checking device state for peer 517
Jul  4 12:13:11 DEBUG[16043]: chan_sip.c:1401 __sip_ack: Stopping retransmission on '3c26700d2bf2-fwnph38q1zr8@snom360-000413231A8A' of Request 105: Match Found