[Mar 20 20:27:19] DEBUG[1139] acl.c: Attached to given IP address
[Mar 20 20:27:19] DEBUG[1139] pbx.c: Function result is '"Pavel Jezek" <324>'
[Mar 20 20:27:19] DEBUG[1139] pbx.c: Launching 'NoOp'
[Mar 20 20:27:19] DEBUG[1139] pbx.c: Launching 'Dial'
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Asked to create a SIP channel with formats: 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Setting NAT on RTP to Off
[Mar 20 20:27:19] DEBUG[1139] acl.c: Found IP address for this socket
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: *** Our native formats are 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: *** Joint capabilities are 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: *** Our capabilities are 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: *** Our preferred formats from the incoming channel are 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: This channel will not be able to handle video.
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Outgoing Call for 324
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Updating call counter for outgoing call
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Our T38 capability (0), joint T38 capability (0)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: ** Our capability: 0x100 (g729) Video flag: False Text flag: False
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: ** Our prefcodec: 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: -- Done with adding codecs to SDP
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Done building SDP. Settling with this capability: 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Initializing initreq for method INVITE - callid 09dde11b19ced0396945ba4729eb5ad4@192.168.40.4
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket...
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Acked pending invite 102
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Stopping retransmission on '09dde11b19ced0396945ba4729eb5ad4@192.168.40.4' of Request 102: Match Found
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Trying to put 'ACK sip:32' onto UDP socket...
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Auth attempt 1 on INVITE
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: ** Our capability: 0x100 (g729) Video flag: False Text flag: False
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: ** Our prefcodec: 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: -- Done with adding codecs to SDP
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Done building SDP. Settling with this capability: 0x100 (g729)
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] sched.c: Attempted to delete nonexistent schedule entry 0!
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket...
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '09dde11b19ced0396945ba4729eb5ad4@192.168.40.4' Request 103: Found
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '09dde11b19ced0396945ba4729eb5ad4@192.168.40.4' Request 103: Found
[Mar 20 20:27:19] DEBUG[1139] devicestate.c: Notification of state change to be queued on device/channel SIP/ipbx-gw-082441c8
[Mar 20 20:27:19] DEBUG[1139] devicestate.c: Notification of state change to be queued on device/channel SIP/ipbx-gw
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Checking device state for peer ipbx-gw-082441c8
[Mar 20 20:27:19] DEBUG[1139] devicestate.c: Changing state for SIP/ipbx-gw-082441c8 - state 1 (Not in use)
[Mar 20 20:27:19] DEBUG[1139] chan_sip.c: Checking device state for peer ipbx-gw
[Mar 20 20:27:19] DEBUG[1139] devicestate.c: Changing state for SIP/ipbx-gw - state 1 (Not in use)
[Mar 20 20:27:19] DEBUG[1139] channel.c: Driver for channel 'H323/ip$192.168.40.7:64201/1138' does not support indication 3, emulating it
[Mar 20 20:27:19] DEBUG[1139] channel.c: Prodding channel 'H323/ip$192.168.40.7:64201/1138'
[Mar 20 20:27:19] WARNING[1139] channel.c: Unable to find a codec translation path from g729 to slin
[Mar 20 20:27:19] WARNING[1139] indications.c: Unable to set 'H323/ip$192.168.40.7:64201/1138' to signed linear format (write)


[Mar 20 20:27:26] DEBUG[1139] chan_sip.c: Acked pending invite 103
[Mar 20 20:27:26] DEBUG[1139] chan_sip.c: Stopping retransmission on '09dde11b19ced0396945ba4729eb5ad4@192.168.40.4' of Request 103: Match Found
[Mar 20 20:27:26] DEBUG[1139] chan_sip.c: We're settling with these formats: 0x100 (g729)
[Mar 20 20:27:26] DEBUG[1139] chan_sip.c: Updating call counter for outgoing call
[Mar 20 20:27:26] DEBUG[1139] chan_sip.c: build_route: Contact hop: <sip:324@193.179.38.20>
[Mar 20 20:27:26] DEBUG[1139] chan_sip.c: Trying to put 'ACK sip:32' onto UDP socket...
[Mar 20 20:27:26] DEBUG[1139] devicestate.c: Notification of state change to be queued on device/channel SIP/ipbx-gw-082441c8
[Mar 20 20:27:26] DEBUG[1139] devicestate.c: Notification of state change to be queued on device/channel SIP/ipbx-gw
[Mar 20 20:27:26] DEBUG[1139] chan_sip.c: Checking device state for peer ipbx-gw-082441c8
[Mar 20 20:27:26] DEBUG[1139] devicestate.c: Changing state for SIP/ipbx-gw-082441c8 - state 1 (Not in use)
[Mar 20 20:27:26] DEBUG[1139] chan_sip.c: Checking device state for peer ipbx-gw
[Mar 20 20:27:26] DEBUG[1139] devicestate.c: Changing state for SIP/ipbx-gw - state 1 (Not in use)
[Mar 20 20:27:26] DEBUG[1139] devicestate.c: Notification of state change to be queued on device/channel H323/ip$192.168.40.7:64201/1138
[Mar 20 20:27:26] DEBUG[1139] devicestate.c: Changing state for H323/ip$192.168.40.7:64201/1138 - state 0 (Unknown)
[Mar 20 20:27:26] DEBUG[1139] rtp.c: Ooh, format changed from unknown to g729
[Mar 20 20:27:26] DEBUG[1139] rtp.c: Created smoother: format: 256 ms: 20 len: 20
[Mar 20 20:27:26] DEBUG[1139] rtp.c: Ooh, format changed from unknown to g729
[Mar 20 20:27:26] DEBUG[1139] rtp.c: Created smoother: format: 256 ms: 10 len: 10
[Mar 20 20:27:28] DEBUG[1139] rtp.c: Got RTCP report of 80 bytes

[Mar 20 20:27:31] DEBUG[1139] chan_sip.c: Setting SIP_ALREADYGONE on dialog 09dde11b19ced0396945ba4729eb5ad4@192.168.40.4
[Mar 20 20:27:31] DEBUG[1139] chan_sip.c: Received bye, issuing owner hangup
[Mar 20 20:27:31] DEBUG[1139] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket...
[Mar 20 20:27:31] DEBUG[1139] channel.c: Didn't get a frame from channel: SIP/ipbx-gw-082441c8
[Mar 20 20:27:31] DEBUG[1139] channel.c: Bridge stops bridging channels H323/ip$192.168.40.7:64201/1138 and SIP/ipbx-gw-082441c8
[Mar 20 20:27:31] DEBUG[1139] channel.c: Hanging up channel 'SIP/ipbx-gw-082441c8'
[Mar 20 20:27:31] DEBUG[1139] chan_sip.c: Hangup call SIP/ipbx-gw-082441c8, SIP callid 09dde11b19ced0396945ba4729eb5ad4@192.168.40.4
[Mar 20 20:27:31] DEBUG[1139] devicestate.c: Notification of state change to be queued on device/channel SIP/ipbx-gw-082441c8
[Mar 20 20:27:31] DEBUG[1139] devicestate.c: Notification of state change to be queued on device/channel SIP/ipbx-gw
[Mar 20 20:27:31] DEBUG[1139] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Mar 20 20:27:31] DEBUG[1139] pbx.c: Spawn extension (from-ccm,*324,2) exited non-zero on 'H323/ip$192.168.40.7:64201/1138'
[Mar 20 20:27:31] DEBUG[1139] channel.c: Soft-Hanging up channel 'H323/ip$192.168.40.7:64201/1138'
[Mar 20 20:27:31] DEBUG[1139] channel.c: Hanging up channel 'H323/ip$192.168.40.7:64201/1138'
[Mar 20 20:27:31] DEBUG[1139] devicestate.c: Notification of state change to be queued on device/channel H323/ip$192.168.40.7:64201/1138
[Mar 20 20:27:31] DEBUG[1139] chan_sip.c: Checking device state for peer ipbx-gw-082441c8
[Mar 20 20:27:31] DEBUG[1139] devicestate.c: Changing state for SIP/ipbx-gw-082441c8 - state 1 (Not in use)
[Mar 20 20:27:31] DEBUG[1139] chan_sip.c: Checking device state for peer ipbx-gw
[Mar 20 20:27:31] DEBUG[1139] devicestate.c: Changing state for SIP/ipbx-gw - state 1 (Not in use)
[Mar 20 20:27:31] DEBUG[1139] devicestate.c: Changing state for H323/ip$192.168.40.7:64201/1138 - state 0 (Unknown)