call2

From kermit, 5 Months ago, written in Plain Text, viewed 30 times.
URL https://pastebin.freepbx.org/view/766c20d5 Embed
Download Paste or View Raw
  1. Domain: atlanta.voip.ms
  2. Status: Registered
  3.  
  4.  
  5. [2017-11-08 10:40:46] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  6. Event: Registry
  7. Privilege: system,all
  8. ChannelType: SIP
  9. Username: 152981_FPBX
  10. Domain: atlanta.voip.ms
  11. Status: Registered
  12.  
  13.  
  14. [2017-11-08 10:40:46] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7409
  15. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 1c16d9d862f8d4f240b901931c30b420@192.168.10.248 - REGISTER (No RTP)
  16. [2017-11-08 10:40:46] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '162.254.144.173', our source address is '192.168.10.248'.
  17. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  18. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'tampa.voip.ms' into...
  19. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'tampa.voip.ms' and port ''.
  20. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'tampa.voip.ms' into...
  21. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'tampa.voip.ms' and port ''.
  22. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'tampa.voip.ms' into...
  23. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'tampa.voip.ms' and port ''.
  24. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method REGISTER - callid 1c16d9d862f8d4f240b901931c30b420@192.168.10.248
  25. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 1 to 107548_freepbx@tampa.voip.ms
  26. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 162.254.144.173:5080
  27. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:15808 __start_register_timeout: Scheduled a registration timeout for tampa.voip.ms id  #56
  28. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7400 on 9806/64 to 192.168.10.53:4569
  29. [2017-11-08 10:40:46] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7429
  30. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 1c16d9d862f8d4f240b901931c30b420@192.168.10.248 (Checking To) --From tag as2ecb2787 --To-tag as0c46c440
  31. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '1c16d9d862f8d4f240b901931c30b420@192.168.10.248' of Request 140: Match Found
  32. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'tampa.voip.ms' into...
  33. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'tampa.voip.ms' and port ''.
  34. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'tampa.voip.ms' into...
  35. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'tampa.voip.ms' and port ''.
  36. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'tampa.voip.ms' into...
  37. [2017-11-08 10:40:46] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'tampa.voip.ms' and port ''.
  38. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:3394 initialize_initreq: Initializing already initialized SIP dialog 1c16d9d862f8d4f240b901931c30b420@192.168.10.248 (presumably reinvite)
  39. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 2 to 107548_freepbx@tampa.voip.ms
  40. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 162.254.144.173:5080
  41. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7420 on 9806/64 to 192.168.10.53:4569
  42. [2017-11-08 10:40:46] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7449
  43. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 1c16d9d862f8d4f240b901931c30b420@192.168.10.248 (Checking To) --From tag as2ecb2787 --To-tag as0c46c440
  44. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '1c16d9d862f8d4f240b901931c30b420@192.168.10.248' of Request 141: Match Found
  45. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:24352 handle_response_register: Registration successful
  46. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:24354 handle_response_register: Cancelling timeout 56
  47. [2017-11-08 10:40:46] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  48. Event: Registry
  49. Privilege: system,all
  50. ChannelType: SIP
  51. Username: 107548_freepbx
  52. Domain: tampa.voip.ms
  53. Status: Registered
  54.  
  55.  
  56. [2017-11-08 10:40:46] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  57. Event: Registry
  58. Privilege: system,all
  59. ChannelType: SIP
  60. Username: 107548_freepbx
  61. Domain: tampa.voip.ms
  62. Status: Registered
  63.  
  64.  
  65. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7440 on 9806/64 to 192.168.10.53:4569
  66. [2017-11-08 10:40:46] DEBUG[2329]: chan_sip.c:6589 sip_pvt_dtor: Destroying SIP dialog 1c16d9d862f8d4f240b901931c30b420@192.168.10.248
  67. [2017-11-08 10:40:46] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7469
  68. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7460 on 9806/64 to 192.168.10.53:4569
  69. [2017-11-08 10:40:46] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7489
  70. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7480 on 9806/64 to 192.168.10.53:4569
  71. [2017-11-08 10:40:46] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7509
  72. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7500 on 9806/64 to 192.168.10.53:4569
  73. [2017-11-08 10:40:46] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7529
  74. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7520 on 9806/64 to 192.168.10.53:4569
  75. [2017-11-08 10:40:46] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7549
  76. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7540 on 9806/64 to 192.168.10.53:4569
  77. [2017-11-08 10:40:46] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7569
  78. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7560 on 9806/64 to 192.168.10.53:4569
  79. [2017-11-08 10:40:46] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7589
  80. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7580 on 9806/64 to 192.168.10.53:4569
  81. [2017-11-08 10:40:46] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7609
  82. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7600 on 9806/64 to 192.168.10.53:4569
  83. [2017-11-08 10:40:46] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7629
  84. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7620 on 9806/64 to 192.168.10.53:4569
  85. [2017-11-08 10:40:46] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7649
  86. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7640 on 9806/64 to 192.168.10.53:4569
  87. [2017-11-08 10:40:46] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7669
  88. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7660 on 9806/64 to 192.168.10.53:4569
  89. [2017-11-08 10:40:46] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7689
  90. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7680 on 9806/64 to 192.168.10.53:4569
  91. [2017-11-08 10:40:46] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7709
  92. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7700 on 9806/64 to 192.168.10.53:4569
  93. [2017-11-08 10:40:46] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7729
  94. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7720 on 9806/64 to 192.168.10.53:4569
  95. [2017-11-08 10:40:46] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7749
  96. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7740 on 9806/64 to 192.168.10.53:4569
  97. [2017-11-08 10:40:46] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7769
  98. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7760 on 9806/64 to 192.168.10.53:4569
  99. [2017-11-08 10:40:46] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7789
  100. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7780 on 9806/64 to 192.168.10.53:4569
  101. [2017-11-08 10:40:46] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7809
  102. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7800 on 9806/64 to 192.168.10.53:4569
  103. [2017-11-08 10:40:46] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7829
  104. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7820 on 9806/64 to 192.168.10.53:4569
  105. [2017-11-08 10:40:46] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7849
  106. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7840 on 9806/64 to 192.168.10.53:4569
  107. [2017-11-08 10:40:46] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7869
  108. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7860 on 9806/64 to 192.168.10.53:4569
  109. [2017-11-08 10:40:46] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7889
  110. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7880 on 9806/64 to 192.168.10.53:4569
  111. [2017-11-08 10:40:46] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7909
  112. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7900 on 9806/64 to 192.168.10.53:4569
  113. [2017-11-08 10:40:46] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7929
  114. [2017-11-08 10:40:46] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7920 on 9806/64 to 192.168.10.53:4569
  115. [2017-11-08 10:40:46] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7949
  116. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7940 on 9806/64 to 192.168.10.53:4569
  117. [2017-11-08 10:40:47] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7969
  118. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7960 on 9806/64 to 192.168.10.53:4569
  119. [2017-11-08 10:40:47] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=7989
  120. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 7980 on 9806/64 to 192.168.10.53:4569
  121. [2017-11-08 10:40:47] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8009
  122. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8000 on 9806/64 to 192.168.10.53:4569
  123. [2017-11-08 10:40:47] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8029
  124. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8020 on 9806/64 to 192.168.10.53:4569
  125. [2017-11-08 10:40:47] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8049
  126. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8040 on 9806/64 to 192.168.10.53:4569
  127. [2017-11-08 10:40:47] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8069
  128. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8060 on 9806/64 to 192.168.10.53:4569
  129. [2017-11-08 10:40:47] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8089
  130. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8080 on 9806/64 to 192.168.10.53:4569
  131. [2017-11-08 10:40:47] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8109
  132. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8100 on 9806/64 to 192.168.10.53:4569
  133. [2017-11-08 10:40:47] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8129
  134. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8120 on 9806/64 to 192.168.10.53:4569
  135. [2017-11-08 10:40:47] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8149
  136. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8140 on 9806/64 to 192.168.10.53:4569
  137. [2017-11-08 10:40:47] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8169
  138. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8160 on 9806/64 to 192.168.10.53:4569
  139. [2017-11-08 10:40:47] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8189
  140. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 68b2b7593dab47e464cb1e50734c60c8@192.168.10.248 - REGISTER (No RTP)
  141. [2017-11-08 10:40:47] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '192.175.96.69', our source address is '192.168.10.248'.
  142. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  143. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal5.voip.ms' into...
  144. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal5.voip.ms' and port ''.
  145. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal5.voip.ms' into...
  146. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal5.voip.ms' and port ''.
  147. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal5.voip.ms' into...
  148. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal5.voip.ms' and port ''.
  149. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method REGISTER - callid 68b2b7593dab47e464cb1e50734c60c8@192.168.10.248
  150. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 1 to 206995_PBX@montreal5.voip.ms
  151. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 192.175.96.69:5060
  152. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:15808 __start_register_timeout: Scheduled a registration timeout for montreal5.voip.ms id  #8
  153. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8180 on 9806/64 to 192.168.10.53:4569
  154. [2017-11-08 10:40:47] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8209
  155. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8200 on 9806/64 to 192.168.10.53:4569
  156. [2017-11-08 10:40:47] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8229
  157. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8220 on 9806/64 to 192.168.10.53:4569
  158. [2017-11-08 10:40:47] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8249
  159. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8240 on 9806/64 to 192.168.10.53:4569
  160. [2017-11-08 10:40:47] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8269
  161. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 68b2b7593dab47e464cb1e50734c60c8@192.168.10.248 (Checking To) --From tag as0178470f --To-tag as338f8a24
  162. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '68b2b7593dab47e464cb1e50734c60c8@192.168.10.248' of Request 140: Match Found
  163. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal5.voip.ms' into...
  164. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal5.voip.ms' and port ''.
  165. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal5.voip.ms' into...
  166. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal5.voip.ms' and port ''.
  167. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal5.voip.ms' into...
  168. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal5.voip.ms' and port ''.
  169. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3394 initialize_initreq: Initializing already initialized SIP dialog 68b2b7593dab47e464cb1e50734c60c8@192.168.10.248 (presumably reinvite)
  170. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 2 to 206995_PBX@montreal5.voip.ms
  171. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 192.175.96.69:5060
  172. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8260 on 9806/64 to 192.168.10.53:4569
  173. [2017-11-08 10:40:47] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8289
  174. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8280 on 9806/64 to 192.168.10.53:4569
  175. [2017-11-08 10:40:47] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8309
  176. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8300 on 9806/64 to 192.168.10.53:4569
  177. [2017-11-08 10:40:47] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8329
  178. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 68b2b7593dab47e464cb1e50734c60c8@192.168.10.248 (Checking To) --From tag as0178470f --To-tag as338f8a24
  179. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '68b2b7593dab47e464cb1e50734c60c8@192.168.10.248' of Request 141: Match Found
  180. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:24352 handle_response_register: Registration successful
  181. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:24354 handle_response_register: Cancelling timeout 8
  182. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:6589 sip_pvt_dtor: Destroying SIP dialog 68b2b7593dab47e464cb1e50734c60c8@192.168.10.248
  183. [2017-11-08 10:40:47] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  184. Event: Registry
  185. Privilege: system,all
  186. ChannelType: SIP
  187. Username: 206995_PBX
  188. Domain: montreal5.voip.ms
  189. Status: Registered
  190.  
  191.  
  192. [2017-11-08 10:40:47] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  193. Event: Registry
  194. Privilege: system,all
  195. ChannelType: SIP
  196. Username: 206995_PBX
  197. Domain: montreal5.voip.ms
  198. Status: Registered
  199.  
  200.  
  201. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8320 on 9806/64 to 192.168.10.53:4569
  202. [2017-11-08 10:40:47] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8349
  203. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8340 on 9806/64 to 192.168.10.53:4569
  204. [2017-11-08 10:40:47] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8369
  205. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8360 on 9806/64 to 192.168.10.53:4569
  206. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 5d0fd76836c57f9760eb9f993a502f80@192.168.10.248:5160 - OPTIONS (No RTP)
  207. [2017-11-08 10:40:47] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '162.254.144.173', our source address is '192.168.10.248'.
  208. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  209. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:8781 change_callid_pvt: SIP call-id changed from '5d0fd76836c57f9760eb9f993a502f80@192.168.10.248:5160' to '5c514f1556c776aa1c9b599b60eab077@192.168.10.248:5160'
  210. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method OPTIONS - callid 5c514f1556c776aa1c9b599b60eab077@192.168.10.248:5160
  211. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 162.254.144.173:5060
  212. [2017-11-08 10:40:47] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8389
  213. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8380 on 9806/64 to 192.168.10.53:4569
  214. [2017-11-08 10:40:47] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8409
  215. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 5c514f1556c776aa1c9b599b60eab077@192.168.10.248:5160 (Checking To) --From tag as2a7f035b --To-tag as1f577709
  216. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '5c514f1556c776aa1c9b599b60eab077@192.168.10.248:5160' of Request 102: Match Found
  217. [2017-11-08 10:40:47] NOTICE[2329]: chan_sip.c:24457 handle_response_peerpoke: Peer 'tomtrunk' is now Reachable. (28ms / 2000ms)
  218. [2017-11-08 10:40:47] DEBUG[2184]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for SIP - tomtrunk
  219. [2017-11-08 10:40:47] DEBUG[2184]: chan_sip.c:30168 sip_devicestate: Checking device state for peer tomtrunk
  220. [2017-11-08 10:40:47] DEBUG[2184]: devicestate.c:474 do_state_change: Changing state for SIP/tomtrunk - state 1 (Not in use)
  221. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:6589 sip_pvt_dtor: Destroying SIP dialog 5c514f1556c776aa1c9b599b60eab077@192.168.10.248:5160
  222. [2017-11-08 10:40:47] DEBUG[2346]: app_queue.c:2491 device_state_cb: Device 'SIP/tomtrunk' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
  223. [2017-11-08 10:40:47] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  224. Event: DeviceStateChange
  225. Privilege: call,all
  226. Device: SIP/tomtrunk
  227. State: NOT_INUSE
  228.  
  229.  
  230. [2017-11-08 10:40:47] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  231. Event: PeerStatus
  232. Privilege: system,all
  233. ChannelType: SIP
  234. Peer: SIP/tomtrunk
  235. PeerStatus: Reachable
  236.  
  237.  
  238. [2017-11-08 10:40:47] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  239. Event: DeviceStateChange
  240. Privilege: call,all
  241. Device: SIP/tomtrunk
  242. State: NOT_INUSE
  243.  
  244.  
  245. [2017-11-08 10:40:47] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  246. Event: PeerStatus
  247. Privilege: system,all
  248. ChannelType: SIP
  249. Peer: SIP/tomtrunk
  250. PeerStatus: Reachable
  251.  
  252.  
  253. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8400 on 9806/64 to 192.168.10.53:4569
  254. [2017-11-08 10:40:47] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8429
  255. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8420 on 9806/64 to 192.168.10.53:4569
  256. [2017-11-08 10:40:47] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8449
  257. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8440 on 9806/64 to 192.168.10.53:4569
  258. [2017-11-08 10:40:47] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8469
  259. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8460 on 9806/64 to 192.168.10.53:4569
  260. [2017-11-08 10:40:47] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8489
  261. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8480 on 9806/64 to 192.168.10.53:4569
  262. [2017-11-08 10:40:47] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8509
  263. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8500 on 9806/64 to 192.168.10.53:4569
  264. [2017-11-08 10:40:47] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8529
  265. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8520 on 9806/64 to 192.168.10.53:4569
  266. [2017-11-08 10:40:47] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8549
  267. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8540 on 9806/64 to 192.168.10.53:4569
  268. [2017-11-08 10:40:47] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8569
  269. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8560 on 9806/64 to 192.168.10.53:4569
  270. [2017-11-08 10:40:47] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8589
  271. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8580 on 9806/64 to 192.168.10.53:4569
  272. [2017-11-08 10:40:47] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8609
  273. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8600 on 9806/64 to 192.168.10.53:4569
  274. [2017-11-08 10:40:47] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8629
  275. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 04d78fd445a03e5e6d5640e745ba7793@192.168.10.248 - REGISTER (No RTP)
  276. [2017-11-08 10:40:47] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '158.85.149.162', our source address is '192.168.10.248'.
  277. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  278. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'dallas.voip.ms' into...
  279. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'dallas.voip.ms' and port ''.
  280. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'dallas.voip.ms' into...
  281. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'dallas.voip.ms' and port ''.
  282. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'dallas.voip.ms' into...
  283. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'dallas.voip.ms' and port ''.
  284. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method REGISTER - callid 04d78fd445a03e5e6d5640e745ba7793@192.168.10.248
  285. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 1 to 204350_FPBX@dallas.voip.ms
  286. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 158.85.149.162:5060
  287. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:15808 __start_register_timeout: Scheduled a registration timeout for dallas.voip.ms id  #66
  288. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8620 on 9806/64 to 192.168.10.53:4569
  289. [2017-11-08 10:40:47] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8649
  290. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 66b9193f1ad38e374a20efaa512eab82@192.168.10.248 - REGISTER (No RTP)
  291. [2017-11-08 10:40:47] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '192.175.96.70', our source address is '192.168.10.248'.
  292. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  293. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal6.voip.ms' into...
  294. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal6.voip.ms' and port ''.
  295. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal6.voip.ms' into...
  296. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal6.voip.ms' and port ''.
  297. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal6.voip.ms' into...
  298. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal6.voip.ms' and port ''.
  299. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method REGISTER - callid 66b9193f1ad38e374a20efaa512eab82@192.168.10.248
  300. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 1 to 107314_PBX@montreal6.voip.ms
  301. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 192.175.96.70:5060
  302. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:15808 __start_register_timeout: Scheduled a registration timeout for montreal6.voip.ms id  #31
  303. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8640 on 9806/64 to 192.168.10.53:4569
  304. [2017-11-08 10:40:47] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8669
  305. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8660 on 9806/64 to 192.168.10.53:4569
  306. [2017-11-08 10:40:47] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8689
  307. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 04d78fd445a03e5e6d5640e745ba7793@192.168.10.248 (Checking To) --From tag as4afa7efc --To-tag as1b83d2b4
  308. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '04d78fd445a03e5e6d5640e745ba7793@192.168.10.248' of Request 140: Match Found
  309. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'dallas.voip.ms' into...
  310. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'dallas.voip.ms' and port ''.
  311. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'dallas.voip.ms' into...
  312. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'dallas.voip.ms' and port ''.
  313. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'dallas.voip.ms' into...
  314. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'dallas.voip.ms' and port ''.
  315. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3394 initialize_initreq: Initializing already initialized SIP dialog 04d78fd445a03e5e6d5640e745ba7793@192.168.10.248 (presumably reinvite)
  316. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 2 to 204350_FPBX@dallas.voip.ms
  317. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 158.85.149.162:5060
  318. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8680 on 9806/64 to 192.168.10.53:4569
  319. [2017-11-08 10:40:47] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8709
  320. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8700 on 9806/64 to 192.168.10.53:4569
  321. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 66b9193f1ad38e374a20efaa512eab82@192.168.10.248 (Checking To) --From tag as32344fab --To-tag as7246fb14
  322. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '66b9193f1ad38e374a20efaa512eab82@192.168.10.248' of Request 140: Match Found
  323. [2017-11-08 10:40:47] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8729
  324. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal6.voip.ms' into...
  325. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal6.voip.ms' and port ''.
  326. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal6.voip.ms' into...
  327. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal6.voip.ms' and port ''.
  328. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal6.voip.ms' into...
  329. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal6.voip.ms' and port ''.
  330. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3394 initialize_initreq: Initializing already initialized SIP dialog 66b9193f1ad38e374a20efaa512eab82@192.168.10.248 (presumably reinvite)
  331. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 2 to 107314_PBX@montreal6.voip.ms
  332. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 192.175.96.70:5060
  333. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8720 on 9806/64 to 192.168.10.53:4569
  334. [2017-11-08 10:40:47] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8749
  335. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 04d78fd445a03e5e6d5640e745ba7793@192.168.10.248 (Checking To) --From tag as4afa7efc --To-tag as1b83d2b4
  336. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8740 on 9806/64 to 192.168.10.53:4569
  337. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '04d78fd445a03e5e6d5640e745ba7793@192.168.10.248' of Request 141: Match Found
  338. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:24352 handle_response_register: Registration successful
  339. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:24354 handle_response_register: Cancelling timeout 66
  340. [2017-11-08 10:40:47] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  341. Event: Registry
  342. Privilege: system,all
  343. ChannelType: SIP
  344. Username: 204350_FPBX
  345. Domain: dallas.voip.ms
  346. Status: Registered
  347.  
  348.  
  349. [2017-11-08 10:40:47] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  350. Event: Registry
  351. Privilege: system,all
  352. ChannelType: SIP
  353. Username: 204350_FPBX
  354. Domain: dallas.voip.ms
  355. Status: Registered
  356.  
  357.  
  358. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:6589 sip_pvt_dtor: Destroying SIP dialog 04d78fd445a03e5e6d5640e745ba7793@192.168.10.248
  359. [2017-11-08 10:40:47] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8769
  360. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8760 on 9806/64 to 192.168.10.53:4569
  361. [2017-11-08 10:40:47] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8789
  362. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 66b9193f1ad38e374a20efaa512eab82@192.168.10.248 (Checking To) --From tag as32344fab --To-tag as7246fb14
  363. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '66b9193f1ad38e374a20efaa512eab82@192.168.10.248' of Request 141: Match Found
  364. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:24352 handle_response_register: Registration successful
  365. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:24354 handle_response_register: Cancelling timeout 31
  366. [2017-11-08 10:40:47] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  367. Event: Registry
  368. Privilege: system,all
  369. ChannelType: SIP
  370. Username: 107314_PBX
  371. Domain: montreal6.voip.ms
  372. Status: Registered
  373.  
  374.  
  375. [2017-11-08 10:40:47] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  376. Event: Registry
  377. Privilege: system,all
  378. ChannelType: SIP
  379. Username: 107314_PBX
  380. Domain: montreal6.voip.ms
  381. Status: Registered
  382.  
  383.  
  384. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:6589 sip_pvt_dtor: Destroying SIP dialog 66b9193f1ad38e374a20efaa512eab82@192.168.10.248
  385. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8780 on 9806/64 to 192.168.10.53:4569
  386. [2017-11-08 10:40:47] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8809
  387. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8800 on 9806/64 to 192.168.10.53:4569
  388. [2017-11-08 10:40:47] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8829
  389. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8820 on 9806/64 to 192.168.10.53:4569
  390. [2017-11-08 10:40:47] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8849
  391. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8840 on 9806/64 to 192.168.10.53:4569
  392. [2017-11-08 10:40:47] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8869
  393. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8860 on 9806/64 to 192.168.10.53:4569
  394. [2017-11-08 10:40:47] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8889
  395. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8880 on 9806/64 to 192.168.10.53:4569
  396. [2017-11-08 10:40:47] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8909
  397. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8900 on 9806/64 to 192.168.10.53:4569
  398. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 5eccae6805bec5023641ef68387fb3c6@192.168.10.248 - REGISTER (No RTP)
  399. [2017-11-08 10:40:47] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '173.248.161.90', our source address is '192.168.10.248'.
  400. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  401. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'denver.voip.ms' into...
  402. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'denver.voip.ms' and port ''.
  403. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'denver.voip.ms' into...
  404. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'denver.voip.ms' and port ''.
  405. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'denver.voip.ms' into...
  406. [2017-11-08 10:40:47] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'denver.voip.ms' and port ''.
  407. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method REGISTER - callid 5eccae6805bec5023641ef68387fb3c6@192.168.10.248
  408. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 1 to 112987_FPBX@denver.voip.ms
  409. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 173.248.161.90:5060
  410. [2017-11-08 10:40:47] DEBUG[2329]: chan_sip.c:15808 __start_register_timeout: Scheduled a registration timeout for denver.voip.ms id  #42
  411. [2017-11-08 10:40:47] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8929
  412. [2017-11-08 10:40:47] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8920 on 9806/64 to 192.168.10.53:4569
  413. [2017-11-08 10:40:48] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8949
  414. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8940 on 9806/64 to 192.168.10.53:4569
  415. [2017-11-08 10:40:48] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8969
  416. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8960 on 9806/64 to 192.168.10.53:4569
  417. [2017-11-08 10:40:48] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=8989
  418. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 8980 on 9806/64 to 192.168.10.53:4569
  419. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 1c5f9eaa4b431c3c679c7ea872110d1f@192.168.10.248 - REGISTER (No RTP)
  420. [2017-11-08 10:40:48] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '192.175.96.68', our source address is '192.168.10.248'.
  421. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  422. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal3.voip.ms' into...
  423. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal3.voip.ms' and port ''.
  424. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal3.voip.ms' into...
  425. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal3.voip.ms' and port ''.
  426. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal3.voip.ms' into...
  427. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal3.voip.ms' and port ''.
  428. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method REGISTER - callid 1c5f9eaa4b431c3c679c7ea872110d1f@192.168.10.248
  429. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 1 to 191382_PBX@montreal3.voip.ms
  430. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 192.175.96.68:5060
  431. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:15808 __start_register_timeout: Scheduled a registration timeout for montreal3.voip.ms id  #4
  432. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 5eccae6805bec5023641ef68387fb3c6@192.168.10.248 (Checking To) --From tag as56f290bf --To-tag as392e8e56
  433. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '5eccae6805bec5023641ef68387fb3c6@192.168.10.248' of Request 140: Match Found
  434. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'denver.voip.ms' into...
  435. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'denver.voip.ms' and port ''.
  436. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'denver.voip.ms' into...
  437. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'denver.voip.ms' and port ''.
  438. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'denver.voip.ms' into...
  439. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'denver.voip.ms' and port ''.
  440. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3394 initialize_initreq: Initializing already initialized SIP dialog 5eccae6805bec5023641ef68387fb3c6@192.168.10.248 (presumably reinvite)
  441. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 2 to 112987_FPBX@denver.voip.ms
  442. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 173.248.161.90:5060
  443. [2017-11-08 10:40:48] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9009
  444. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9000 on 9806/64 to 192.168.10.53:4569
  445. [2017-11-08 10:40:48] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9029
  446. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9020 on 9806/64 to 192.168.10.53:4569
  447. [2017-11-08 10:40:48] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9049
  448. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9040 on 9806/64 to 192.168.10.53:4569
  449. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 1c5f9eaa4b431c3c679c7ea872110d1f@192.168.10.248 (Checking To) --From tag as17baec80 --To-tag as384a414e
  450. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '1c5f9eaa4b431c3c679c7ea872110d1f@192.168.10.248' of Request 140: Match Found
  451. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal3.voip.ms' into...
  452. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal3.voip.ms' and port ''.
  453. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal3.voip.ms' into...
  454. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal3.voip.ms' and port ''.
  455. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'montreal3.voip.ms' into...
  456. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'montreal3.voip.ms' and port ''.
  457. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3394 initialize_initreq: Initializing already initialized SIP dialog 1c5f9eaa4b431c3c679c7ea872110d1f@192.168.10.248 (presumably reinvite)
  458. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 2 to 191382_PBX@montreal3.voip.ms
  459. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 192.175.96.68:5060
  460. [2017-11-08 10:40:48] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9069
  461. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9060 on 9806/64 to 192.168.10.53:4569
  462. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 5eccae6805bec5023641ef68387fb3c6@192.168.10.248 (Checking To) --From tag as56f290bf --To-tag as392e8e56
  463. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '5eccae6805bec5023641ef68387fb3c6@192.168.10.248' of Request 141: Match Found
  464. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:24352 handle_response_register: Registration successful
  465. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:24354 handle_response_register: Cancelling timeout 42
  466. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  467. Event: Registry
  468. Privilege: system,all
  469. ChannelType: SIP
  470. Username: 112987_FPBX
  471. Domain: denver.voip.ms
  472. Status: Registered
  473.  
  474.  
  475. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  476. Event: Registry
  477. Privilege: system,all
  478. ChannelType: SIP
  479. Username: 112987_FPBX
  480. Domain: denver.voip.ms
  481. Status: Registered
  482.  
  483.  
  484. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:6589 sip_pvt_dtor: Destroying SIP dialog 5eccae6805bec5023641ef68387fb3c6@192.168.10.248
  485. [2017-11-08 10:40:48] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9089
  486. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9080 on 9806/64 to 192.168.10.53:4569
  487. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9109
  488. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9100 on 9806/64 to 192.168.10.53:4569
  489. [2017-11-08 10:40:48] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9129
  490. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9120 on 9806/64 to 192.168.10.53:4569
  491. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 1c5f9eaa4b431c3c679c7ea872110d1f@192.168.10.248 (Checking To) --From tag as17baec80 --To-tag as384a414e
  492. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '1c5f9eaa4b431c3c679c7ea872110d1f@192.168.10.248' of Request 141: Match Found
  493. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:24352 handle_response_register: Registration successful
  494. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:24354 handle_response_register: Cancelling timeout 4
  495. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  496. Event: Registry
  497. Privilege: system,all
  498. ChannelType: SIP
  499. Username: 191382_PBX
  500. Domain: montreal3.voip.ms
  501. Status: Registered
  502.  
  503.  
  504. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  505. Event: Registry
  506. Privilege: system,all
  507. ChannelType: SIP
  508. Username: 191382_PBX
  509. Domain: montreal3.voip.ms
  510. Status: Registered
  511.  
  512.  
  513. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:6589 sip_pvt_dtor: Destroying SIP dialog 1c5f9eaa4b431c3c679c7ea872110d1f@192.168.10.248
  514. [2017-11-08 10:40:48] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9149
  515. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9140 on 9806/64 to 192.168.10.53:4569
  516. [2017-11-08 10:40:48] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9169
  517. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9160 on 9806/64 to 192.168.10.53:4569
  518. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 2bda6f2116d9fdd70a6b9c136c57c9c7@192.168.10.248 - REGISTER (No RTP)
  519. [2017-11-08 10:40:48] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '96.44.149.186', our source address is '192.168.10.248'.
  520. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  521. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'losangeles.voip.ms' into...
  522. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'losangeles.voip.ms' and port ''.
  523. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'losangeles.voip.ms' into...
  524. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'losangeles.voip.ms' and port ''.
  525. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'losangeles.voip.ms' into...
  526. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'losangeles.voip.ms' and port ''.
  527. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method REGISTER - callid 2bda6f2116d9fdd70a6b9c136c57c9c7@192.168.10.248
  528. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 1 to 106479_himynameis@losangeles.voip.ms
  529. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 96.44.149.186:5060
  530. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:15808 __start_register_timeout: Scheduled a registration timeout for losangeles.voip.ms id  #44
  531. [2017-11-08 10:40:48] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9189
  532. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9180 on 9806/64 to 192.168.10.53:4569
  533. [2017-11-08 10:40:48] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9209
  534. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9200 on 9806/64 to 192.168.10.53:4569
  535. [2017-11-08 10:40:48] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9229
  536. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9220 on 9806/64 to 192.168.10.53:4569
  537. [2017-11-08 10:40:48] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9249
  538. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9240 on 9806/64 to 192.168.10.53:4569
  539. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 2bda6f2116d9fdd70a6b9c136c57c9c7@192.168.10.248 (Checking To) --From tag as0f5541cd --To-tag as136bf603
  540. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '2bda6f2116d9fdd70a6b9c136c57c9c7@192.168.10.248' of Request 140: Match Found
  541. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'losangeles.voip.ms' into...
  542. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'losangeles.voip.ms' and port ''.
  543. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'losangeles.voip.ms' into...
  544. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'losangeles.voip.ms' and port ''.
  545. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:172 ast_sockaddr_split_hostport: Splitting 'losangeles.voip.ms' into...
  546. [2017-11-08 10:40:48] DEBUG[2329]: netsock2.c:226 ast_sockaddr_split_hostport: ...host 'losangeles.voip.ms' and port ''.
  547. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3394 initialize_initreq: Initializing already initialized SIP dialog 2bda6f2116d9fdd70a6b9c136c57c9c7@192.168.10.248 (presumably reinvite)
  548. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:16079 transmit_register: REGISTER attempt 2 to 106479_himynameis@losangeles.voip.ms
  549. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 96.44.149.186:5060
  550. [2017-11-08 10:40:48] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9269
  551. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9260 on 9806/64 to 192.168.10.53:4569
  552. [2017-11-08 10:40:48] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9289
  553. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9280 on 9806/64 to 192.168.10.53:4569
  554. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9309
  555. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9300 on 9806/64 to 192.168.10.53:4569
  556. [2017-11-08 10:40:48] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9329
  557. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9320 on 9806/64 to 192.168.10.53:4569
  558. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:9409 __find_call: = Looking for  Call ID: 2bda6f2116d9fdd70a6b9c136c57c9c7@192.168.10.248 (Checking To) --From tag as0f5541cd --To-tag as136bf603
  559. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:4537 __sip_ack: Stopping retransmission on '2bda6f2116d9fdd70a6b9c136c57c9c7@192.168.10.248' of Request 141: Match Found
  560. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:24352 handle_response_register: Registration successful
  561. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:24354 handle_response_register: Cancelling timeout 44
  562. [2017-11-08 10:40:48] DEBUG[2329]: chan_sip.c:6589 sip_pvt_dtor: Destroying SIP dialog 2bda6f2116d9fdd70a6b9c136c57c9c7@192.168.10.248
  563. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  564. Event: Registry
  565. Privilege: system,all
  566. ChannelType: SIP
  567. Username: 106479_himynameis
  568. Domain: losangeles.voip.ms
  569. Status: Registered
  570.  
  571.  
  572. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  573. Event: Registry
  574. Privilege: system,all
  575. ChannelType: SIP
  576. Username: 106479_himynameis
  577. Domain: losangeles.voip.ms
  578. Status: Registered
  579.  
  580.  
  581. [2017-11-08 10:40:48] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9349
  582. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9340 on 9806/64 to 192.168.10.53:4569
  583. [2017-11-08 10:40:48] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9369
  584. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9360 on 9806/64 to 192.168.10.53:4569
  585. [2017-11-08 10:40:48] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9389
  586. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9380 on 9806/64 to 192.168.10.53:4569
  587. [2017-11-08 10:40:48] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9409
  588. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9400 on 9806/64 to 192.168.10.53:4569
  589. [2017-11-08 10:40:48] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9429
  590. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9420 on 9806/64 to 192.168.10.53:4569
  591. [2017-11-08 10:40:48] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9449
  592. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9440 on 9806/64 to 192.168.10.53:4569
  593. [2017-11-08 10:40:48] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9469
  594. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9460 on 9806/64 to 192.168.10.53:4569
  595. [2017-11-08 10:40:48] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9489
  596. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9480 on 9806/64 to 192.168.10.53:4569
  597. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9509
  598. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9500 on 9806/64 to 192.168.10.53:4569
  599. [2017-11-08 10:40:48] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9529
  600. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9520 on 9806/64 to 192.168.10.53:4569
  601. [2017-11-08 10:40:48] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9549
  602. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9540 on 9806/64 to 192.168.10.53:4569
  603. [2017-11-08 10:40:48] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9569
  604. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9560 on 9806/64 to 192.168.10.53:4569
  605. [2017-11-08 10:40:48] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9589
  606. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9580 on 9806/64 to 192.168.10.53:4569
  607. [2017-11-08 10:40:48] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9609
  608. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9600 on 9806/64 to 192.168.10.53:4569
  609. [2017-11-08 10:40:48] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9629
  610. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9620 on 9806/64 to 192.168.10.53:4569
  611. [2017-11-08 10:40:48] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9649
  612. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9640 on 9806/64 to 192.168.10.53:4569
  613. [2017-11-08 10:40:48] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9669
  614. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9660 on 9806/64 to 192.168.10.53:4569
  615. [2017-11-08 10:40:48] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9689
  616. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9680 on 9806/64 to 192.168.10.53:4569
  617. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9709
  618. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9700 on 9806/64 to 192.168.10.53:4569
  619. [2017-11-08 10:40:48] DEBUG[2320]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9729
  620. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9720 on 9806/64 to 192.168.10.53:4569
  621. [2017-11-08 10:40:48] DEBUG[2318]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9749
  622. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9740 on 9806/64 to 192.168.10.53:4569
  623. [2017-11-08 10:40:48] DEBUG[2321]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9769
  624. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9760 on 9806/64 to 192.168.10.53:4569
  625. [2017-11-08 10:40:48] DEBUG[2326]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9789
  626. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9780 on 9806/64 to 192.168.10.53:4569
  627. [2017-11-08 10:40:48] DEBUG[2322]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9809
  628. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9800 on 9806/64 to 192.168.10.53:4569
  629. [2017-11-08 10:40:48] DEBUG[2324]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9829
  630. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9820 on 9806/64 to 192.168.10.53:4569
  631. [2017-11-08 10:40:48] DEBUG[2325]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9849
  632. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9840 on 9806/64 to 192.168.10.53:4569
  633. [2017-11-08 10:40:48] DEBUG[2323]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9869
  634. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9860 on 9806/64 to 192.168.10.53:4569
  635. [2017-11-08 10:40:48] DEBUG[2317]: chan_iax2.c:11961 socket_process_helper: For call=9806, set last=9889
  636. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3432 send_packet: Sending 9880 on 9806/64 to 192.168.10.53:4569
  637. Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass: HANGUP
  638.    Timestamp: 09891ms  SCall: 00064  DCall: 09806 192.168.10.53:4569
  639.    CAUSE CODE      : 16
  640.  
  641. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:10379 socket_process_helper: Received packet 3, (6, 5)
  642. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:10650 socket_process_helper: IAX subclass 5 received
  643. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:10659 socket_process_helper: For call=9806, set last=9891
  644. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:10971 socket_process_helper: Immediately destroying 9806, having received hangup
  645. [2017-11-08 10:40:48] DEBUG[2319]: chan_iax2.c:3432 send_packet: Sending 9891 on 9806/64 to 192.168.10.53:4569
  646. Tx-Frame Retry[-01] -- OSeqno: 005 ISeqno: 004 Type: IAX     Subclass: ACK
  647.    Timestamp: 09891ms  SCall: 09806  DCall: 00064 192.168.10.53:4569
  648. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  649. Event: HangupRequest
  650. Privilege: call,all
  651. Channel: IAX2/222-9806
  652. ChannelState: 7
  653. ChannelStateDesc: Busy
  654. CallerIDNum: 222
  655. CallerIDName: Roy
  656. ConnectedLineNum: <unknown>
  657. ConnectedLineName: <unknown>
  658. Language: en
  659. AccountCode:
  660. Context: macro-outisbusy
  661. Exten: s
  662. Priority: 5
  663. Uniqueid: 1510159241.1215
  664. Linkedid: 1510159241.1215
  665.  
  666.  
  667. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  668. Event: HangupRequest
  669. Privilege: call,all
  670. Channel: IAX2/222-9806
  671. ChannelState: 7
  672. ChannelStateDesc: Busy
  673. CallerIDNum: 222
  674. CallerIDName: Roy
  675. ConnectedLineNum: <unknown>
  676. ConnectedLineName: <unknown>
  677. Language: en
  678. AccountCode:
  679. Context: macro-outisbusy
  680. Exten: s
  681. Priority: 5
  682. Uniqueid: 1510159241.1215
  683. Linkedid: 1510159241.1215
  684.  
  685.  
  686. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: channel.c:3469 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second
  687. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: channel.c:8118 deactivate_silence_generator: Trying to stop silence generator when there is no generator on 'IAX2/222-9806'
  688. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: app_macro.c:453 _macro_exec: Spawn extension (macro-outisbusy,s,5) exited non-zero on 'IAX2/222-9806' in macro 'outisbusy'
  689.   == Spawn extension (macro-outisbusy, s, 5) exited non-zero on 'IAX2/222-9806' in macro 'outisbusy'
  690. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  691. Event: VarSet
  692. Privilege: dialplan,all
  693. Channel: IAX2/222-9806
  694. ChannelState: 7
  695. ChannelStateDesc: Busy
  696. CallerIDNum: 222
  697. CallerIDName: Roy
  698. ConnectedLineNum: <unknown>
  699. ConnectedLineName: <unknown>
  700. Language: en
  701. AccountCode:
  702. Context: macro-outisbusy
  703. Exten: s
  704. Priority: 5
  705. Uniqueid: 1510159241.1215
  706. Linkedid: 1510159241.1215
  707. Variable: MACRO_DEPTH
  708. Value: 0
  709.  
  710.  
  711. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  712. Event: VarSet
  713. Privilege: dialplan,all
  714. Channel: IAX2/222-9806
  715. ChannelState: 7
  716. ChannelStateDesc: Busy
  717. CallerIDNum: 222
  718. CallerIDName: Roy
  719. ConnectedLineNum: <unknown>
  720. ConnectedLineName: <unknown>
  721. Language: en
  722. AccountCode:
  723. Context: macro-outisbusy
  724. Exten: s
  725. Priority: 5
  726. Uniqueid: 1510159241.1215
  727. Linkedid: 1510159241.1215
  728. Variable: MACRO_DEPTH
  729. Value: 0
  730.  
  731.  
  732. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  733. Event: VarSet
  734. Privilege: dialplan,all
  735. Channel: IAX2/222-9806
  736. ChannelState: 7
  737. ChannelStateDesc: Busy
  738. CallerIDNum: 222
  739. CallerIDName: Roy
  740. ConnectedLineNum: <unknown>
  741. ConnectedLineName: <unknown>
  742. Language: en
  743. AccountCode:
  744. Context: macro-outisbusy
  745. Exten: s
  746. Priority: 5
  747. Uniqueid: 1510159241.1215
  748. Linkedid: 1510159241.1215
  749. Variable: MACRO_EXTEN
  750. Value:
  751.  
  752.  
  753. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  754. Event: VarSet
  755. Privilege: dialplan,all
  756. Channel: IAX2/222-9806
  757. ChannelState: 7
  758. ChannelStateDesc: Busy
  759. CallerIDNum: 222
  760. CallerIDName: Roy
  761. ConnectedLineNum: <unknown>
  762. ConnectedLineName: <unknown>
  763. Language: en
  764. AccountCode:
  765. Context: macro-outisbusy
  766. Exten: s
  767. Priority: 5
  768. Uniqueid: 1510159241.1215
  769. Linkedid: 1510159241.1215
  770. Variable: MACRO_EXTEN
  771. Value:
  772.  
  773.  
  774. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  775. Event: VarSet
  776. Privilege: dialplan,all
  777. Channel: IAX2/222-9806
  778. ChannelState: 7
  779. ChannelStateDesc: Busy
  780. CallerIDNum: 222
  781. CallerIDName: Roy
  782. ConnectedLineNum: <unknown>
  783. ConnectedLineName: <unknown>
  784. Language: en
  785. AccountCode:
  786. Context: macro-outisbusy
  787. Exten: s
  788. Priority: 5
  789. Uniqueid: 1510159241.1215
  790. Linkedid: 1510159241.1215
  791. Variable: MACRO_CONTEXT
  792. Value:
  793.  
  794.  
  795. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  796. Event: VarSet
  797. Privilege: dialplan,all
  798. Channel: IAX2/222-9806
  799. ChannelState: 7
  800. ChannelStateDesc: Busy
  801. CallerIDNum: 222
  802. CallerIDName: Roy
  803. ConnectedLineNum: <unknown>
  804. ConnectedLineName: <unknown>
  805. Language: en
  806. AccountCode:
  807. Context: macro-outisbusy
  808. Exten: s
  809. Priority: 5
  810. Uniqueid: 1510159241.1215
  811. Linkedid: 1510159241.1215
  812. Variable: MACRO_CONTEXT
  813. Value:
  814.  
  815.  
  816. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  817. Event: VarSet
  818. Privilege: dialplan,all
  819. Channel: IAX2/222-9806
  820. ChannelState: 7
  821. ChannelStateDesc: Busy
  822. CallerIDNum: 222
  823. CallerIDName: Roy
  824. ConnectedLineNum: <unknown>
  825. ConnectedLineName: <unknown>
  826. Language: en
  827. AccountCode:
  828. Context: macro-outisbusy
  829. Exten: s
  830. Priority: 5
  831. Uniqueid: 1510159241.1215
  832. Linkedid: 1510159241.1215
  833. Variable: MACRO_PRIORITY
  834. Value:
  835.  
  836.  
  837. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  838. Event: VarSet
  839. Privilege: dialplan,all
  840. Channel: IAX2/222-9806
  841. ChannelState: 7
  842. ChannelStateDesc: Busy
  843. CallerIDNum: 222
  844. CallerIDName: Roy
  845. ConnectedLineNum: <unknown>
  846. ConnectedLineName: <unknown>
  847. Language: en
  848. AccountCode:
  849. Context: macro-outisbusy
  850. Exten: s
  851. Priority: 5
  852. Uniqueid: 1510159241.1215
  853. Linkedid: 1510159241.1215
  854. Variable: MACRO_PRIORITY
  855. Value:
  856.  
  857.  
  858. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx.c:4346 __ast_pbx_run: Spawn extension (from-internal,8604000023,7) exited non-zero on 'IAX2/222-9806'
  859.   == Spawn extension (from-internal, 8604000023, 7) exited non-zero on 'IAX2/222-9806'
  860. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: channel.c:2579 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'IAX2/222-9806'
  861. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  862. Event: SoftHangupRequest
  863. Privilege: call,all
  864. Channel: IAX2/222-9806
  865. ChannelState: 7
  866. ChannelStateDesc: Busy
  867. CallerIDNum: 222
  868. CallerIDName: Roy
  869. ConnectedLineNum: <unknown>
  870. ConnectedLineName: <unknown>
  871. Language: en
  872. AccountCode:
  873. Context: from-internal
  874. Exten: 8604000023
  875. Priority: 7
  876. Uniqueid: 1510159241.1215
  877. Linkedid: 1510159241.1215
  878. Cause: 16
  879.  
  880.  
  881. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  882. Event: SoftHangupRequest
  883. Privilege: call,all
  884. Channel: IAX2/222-9806
  885. ChannelState: 7
  886. ChannelStateDesc: Busy
  887. CallerIDNum: 222
  888. CallerIDName: Roy
  889. ConnectedLineNum: <unknown>
  890. ConnectedLineName: <unknown>
  891. Language: en
  892. AccountCode:
  893. Context: from-internal
  894. Exten: 8604000023
  895. Priority: 7
  896. Uniqueid: 1510159241.1215
  897. Linkedid: 1510159241.1215
  898. Cause: 16
  899.  
  900.  
  901. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: channel.c:2579 ast_softhangup_nolock: Soft-Hanging (0x80) up channel 'IAX2/222-9806'
  902. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx.c:2875 pbx_extension_helper: Launching 'Macro'
  903.     -- Executing [h@from-internal:1] Macro("IAX2/222-9806", "hangupcall") in new stack
  904. [2017-11-08 10:40:48] DEBUG[2209]: cdr.c:1293 cdr_object_finalize: Finalized CDR for IAX2/222-9806 - start 1510159241.049083 answer 0.000000 end 1510159248.957227 dispo FAILED
  905. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  906. Event: Newexten
  907. Privilege: call,all
  908. Channel: IAX2/222-9806
  909. ChannelState: 7
  910. ChannelStateDesc: Busy
  911. CallerIDNum: 222
  912. CallerIDName: Roy
  913. ConnectedLineNum: <unknown>
  914. ConnectedLineName: <unknown>
  915. Language: en
  916. AccountCode:
  917. Context: from-internal
  918. Exten: h
  919. Priority: 1
  920. Uniqueid: 1510159241.1215
  921. Linkedid: 1510159241.1215
  922. Extension: h
  923. Application: Macro
  924. AppData: hangupcall
  925.  
  926.  
  927. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  928. Event: Newexten
  929. Privilege: call,all
  930. Channel: IAX2/222-9806
  931. ChannelState: 7
  932. ChannelStateDesc: Busy
  933. CallerIDNum: 222
  934. CallerIDName: Roy
  935. ConnectedLineNum: <unknown>
  936. ConnectedLineName: <unknown>
  937. Language: en
  938. AccountCode:
  939. Context: from-internal
  940. Exten: h
  941. Priority: 1
  942. Uniqueid: 1510159241.1215
  943. Linkedid: 1510159241.1215
  944. Extension: h
  945. Application: Macro
  946. AppData: hangupcall
  947.  
  948.  
  949. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  950. Event: VarSet
  951. Privilege: dialplan,all
  952. Channel: IAX2/222-9806
  953. ChannelState: 7
  954. ChannelStateDesc: Busy
  955. CallerIDNum: 222
  956. CallerIDName: Roy
  957. ConnectedLineNum: <unknown>
  958. ConnectedLineName: <unknown>
  959. Language: en
  960. AccountCode:
  961. Context: from-internal
  962. Exten: h
  963. Priority: 1
  964. Uniqueid: 1510159241.1215
  965. Linkedid: 1510159241.1215
  966. Variable: MACRO_IN_HANGUP
  967. Value: 1
  968.  
  969.  
  970. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  971. Event: VarSet
  972. Privilege: dialplan,all
  973. Channel: IAX2/222-9806
  974. ChannelState: 7
  975. ChannelStateDesc: Busy
  976. CallerIDNum: 222
  977. CallerIDName: Roy
  978. ConnectedLineNum: <unknown>
  979. ConnectedLineName: <unknown>
  980. Language: en
  981. AccountCode:
  982. Context: from-internal
  983. Exten: h
  984. Priority: 1
  985. Uniqueid: 1510159241.1215
  986. Linkedid: 1510159241.1215
  987. Variable: MACRO_IN_HANGUP
  988. Value: 1
  989.  
  990.  
  991. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  992. Event: VarSet
  993. Privilege: dialplan,all
  994. Channel: IAX2/222-9806
  995. ChannelState: 7
  996. ChannelStateDesc: Busy
  997. CallerIDNum: 222
  998. CallerIDName: Roy
  999. ConnectedLineNum: <unknown>
  1000. ConnectedLineName: <unknown>
  1001. Language: en
  1002. AccountCode:
  1003. Context: from-internal
  1004. Exten: h
  1005. Priority: 1
  1006. Uniqueid: 1510159241.1215
  1007. Linkedid: 1510159241.1215
  1008. Variable: MACRO_EXTEN
  1009. Value: h
  1010.  
  1011.  
  1012. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1013. Event: VarSet
  1014. Privilege: dialplan,all
  1015. Channel: IAX2/222-9806
  1016. ChannelState: 7
  1017. ChannelStateDesc: Busy
  1018. CallerIDNum: 222
  1019. CallerIDName: Roy
  1020. ConnectedLineNum: <unknown>
  1021. ConnectedLineName: <unknown>
  1022. Language: en
  1023. AccountCode:
  1024. Context: from-internal
  1025. Exten: h
  1026. Priority: 1
  1027. Uniqueid: 1510159241.1215
  1028. Linkedid: 1510159241.1215
  1029. Variable: MACRO_EXTEN
  1030. Value: h
  1031.  
  1032.  
  1033. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1034. Event: VarSet
  1035. Privilege: dialplan,all
  1036. Channel: IAX2/222-9806
  1037. ChannelState: 7
  1038. ChannelStateDesc: Busy
  1039. CallerIDNum: 222
  1040. CallerIDName: Roy
  1041. ConnectedLineNum: <unknown>
  1042. ConnectedLineName: <unknown>
  1043. Language: en
  1044. AccountCode:
  1045. Context: from-internal
  1046. Exten: h
  1047. Priority: 1
  1048. Uniqueid: 1510159241.1215
  1049. Linkedid: 1510159241.1215
  1050. Variable: MACRO_CONTEXT
  1051. Value: from-internal
  1052.  
  1053.  
  1054. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1055. Event: VarSet
  1056. Privilege: dialplan,all
  1057. Channel: IAX2/222-9806
  1058. ChannelState: 7
  1059. ChannelStateDesc: Busy
  1060. CallerIDNum: 222
  1061. CallerIDName: Roy
  1062. ConnectedLineNum: <unknown>
  1063. ConnectedLineName: <unknown>
  1064. Language: en
  1065. AccountCode:
  1066. Context: from-internal
  1067. Exten: h
  1068. Priority: 1
  1069. Uniqueid: 1510159241.1215
  1070. Linkedid: 1510159241.1215
  1071. Variable: MACRO_CONTEXT
  1072. Value: from-internal
  1073.  
  1074.  
  1075. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1076. Event: VarSet
  1077. Privilege: dialplan,all
  1078. Channel: IAX2/222-9806
  1079. ChannelState: 7
  1080. ChannelStateDesc: Busy
  1081. CallerIDNum: 222
  1082. CallerIDName: Roy
  1083. ConnectedLineNum: <unknown>
  1084. ConnectedLineName: <unknown>
  1085. Language: en
  1086. AccountCode:
  1087. Context: from-internal
  1088. Exten: h
  1089. Priority: 1
  1090. Uniqueid: 1510159241.1215
  1091. Linkedid: 1510159241.1215
  1092. Variable: MACRO_PRIORITY
  1093. Value: 1
  1094.  
  1095.  
  1096. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1097. Event: VarSet
  1098. Privilege: dialplan,all
  1099. Channel: IAX2/222-9806
  1100. ChannelState: 7
  1101. ChannelStateDesc: Busy
  1102. CallerIDNum: 222
  1103. CallerIDName: Roy
  1104. ConnectedLineNum: <unknown>
  1105. ConnectedLineName: <unknown>
  1106. Language: en
  1107. AccountCode:
  1108. Context: from-internal
  1109. Exten: h
  1110. Priority: 1
  1111. Uniqueid: 1510159241.1215
  1112. Linkedid: 1510159241.1215
  1113. Variable: MACRO_PRIORITY
  1114. Value: 1
  1115.  
  1116.  
  1117. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1118. Event: VarSet
  1119. Privilege: dialplan,all
  1120. Channel: IAX2/222-9806
  1121. ChannelState: 7
  1122. ChannelStateDesc: Busy
  1123. CallerIDNum: 222
  1124. CallerIDName: Roy
  1125. ConnectedLineNum: <unknown>
  1126. ConnectedLineName: <unknown>
  1127. Language: en
  1128. AccountCode:
  1129. Context: from-internal
  1130. Exten: h
  1131. Priority: 1
  1132. Uniqueid: 1510159241.1215
  1133. Linkedid: 1510159241.1215
  1134. Variable: MACRO_DEPTH
  1135. Value: 1
  1136.  
  1137.  
  1138. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1139. Event: VarSet
  1140. Privilege: dialplan,all
  1141. Channel: IAX2/222-9806
  1142. ChannelState: 7
  1143. ChannelStateDesc: Busy
  1144. CallerIDNum: 222
  1145. CallerIDName: Roy
  1146. ConnectedLineNum: <unknown>
  1147. ConnectedLineName: <unknown>
  1148. Language: en
  1149. AccountCode:
  1150. Context: from-internal
  1151. Exten: h
  1152. Priority: 1
  1153. Uniqueid: 1510159241.1215
  1154. Linkedid: 1510159241.1215
  1155. Variable: MACRO_DEPTH
  1156. Value: 1
  1157.  
  1158.  
  1159. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1160. Event: VarSet
  1161. Privilege: dialplan,all
  1162. Channel: IAX2/222-9806
  1163. ChannelState: 7
  1164. ChannelStateDesc: Busy
  1165. CallerIDNum: 222
  1166. CallerIDName: Roy
  1167. ConnectedLineNum: <unknown>
  1168. ConnectedLineName: <unknown>
  1169. Language: en
  1170. AccountCode:
  1171. Context: from-internal
  1172. Exten: h
  1173. Priority: 1
  1174. Uniqueid: 1510159241.1215
  1175. Linkedid: 1510159241.1215
  1176. Variable: MACRO_DEPTH
  1177. Value: 1
  1178.  
  1179.  
  1180. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1181. Event: VarSet
  1182. Privilege: dialplan,all
  1183. Channel: IAX2/222-9806
  1184. ChannelState: 7
  1185. ChannelStateDesc: Busy
  1186. CallerIDNum: 222
  1187. CallerIDName: Roy
  1188. ConnectedLineNum: <unknown>
  1189. ConnectedLineName: <unknown>
  1190. Language: en
  1191. AccountCode:
  1192. Context: from-internal
  1193. Exten: h
  1194. Priority: 1
  1195. Uniqueid: 1510159241.1215
  1196. Linkedid: 1510159241.1215
  1197. Variable: MACRO_DEPTH
  1198. Value: 1
  1199.  
  1200.  
  1201. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:378 ast_str_retrieve_variable: Result of 'USE_CONFIRMATION' is NULL
  1202. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:378 ast_str_retrieve_variable: Result of 'RINGGROUP_INDEX' is NULL
  1203. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:381 ast_str_retrieve_variable: Result of 'CHANNEL' is 'IAX2/222-9806'
  1204. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:378 ast_str_retrieve_variable: Result of 'UNIQCHAN' is NULL
  1205. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:777 pbx_substitute_variables_helper_full: Expression result is '1'
  1206. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx.c:2875 pbx_extension_helper: Launching 'GotoIf'
  1207.     -- Executing [s@macro-hangupcall:1] GotoIf("IAX2/222-9806", "1?theend") in new stack
  1208. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1209. Event: Newexten
  1210. Privilege: call,all
  1211. Channel: IAX2/222-9806
  1212. ChannelState: 7
  1213. ChannelStateDesc: Busy
  1214. CallerIDNum: 222
  1215. CallerIDName: Roy
  1216. ConnectedLineNum: <unknown>
  1217. ConnectedLineName: <unknown>
  1218. Language: en
  1219. AccountCode:
  1220. Context: macro-hangupcall
  1221. Exten: s
  1222. Priority: 1
  1223. Uniqueid: 1510159241.1215
  1224. Linkedid: 1510159241.1215
  1225. Extension: s
  1226. Application: GotoIf
  1227. AppData: 1?theend
  1228.  
  1229.  
  1230. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1231. Event: Newexten
  1232. Privilege: call,all
  1233. Channel: IAX2/222-9806
  1234. ChannelState: 7
  1235. ChannelStateDesc: Busy
  1236. CallerIDNum: 222
  1237. CallerIDName: Roy
  1238. ConnectedLineNum: <unknown>
  1239. ConnectedLineName: <unknown>
  1240. Language: en
  1241. AccountCode:
  1242. Context: macro-hangupcall
  1243. Exten: s
  1244. Priority: 1
  1245. Uniqueid: 1510159241.1215
  1246. Linkedid: 1510159241.1215
  1247. Extension: s
  1248. Application: GotoIf
  1249. AppData: 1?theend
  1250.  
  1251.  
  1252.     -- Goto (macro-hangupcall,s,3)
  1253. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: app_macro.c:459 _macro_exec: Executed application: GotoIf
  1254. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1255. Event: VarSet
  1256. Privilege: dialplan,all
  1257. Channel: IAX2/222-9806
  1258. ChannelState: 7
  1259. ChannelStateDesc: Busy
  1260. CallerIDNum: 222
  1261. CallerIDName: Roy
  1262. ConnectedLineNum: <unknown>
  1263. ConnectedLineName: <unknown>
  1264. Language: en
  1265. AccountCode:
  1266. Context: macro-hangupcall
  1267. Exten: s
  1268. Priority: 1
  1269. Uniqueid: 1510159241.1215
  1270. Linkedid: 1510159241.1215
  1271. Variable: MACRO_DEPTH
  1272. Value: 1
  1273.  
  1274.  
  1275. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1276. Event: VarSet
  1277. Privilege: dialplan,all
  1278. Channel: IAX2/222-9806
  1279. ChannelState: 7
  1280. ChannelStateDesc: Busy
  1281. CallerIDNum: 222
  1282. CallerIDName: Roy
  1283. ConnectedLineNum: <unknown>
  1284. ConnectedLineName: <unknown>
  1285. Language: en
  1286. AccountCode:
  1287. Context: macro-hangupcall
  1288. Exten: s
  1289. Priority: 1
  1290. Uniqueid: 1510159241.1215
  1291. Linkedid: 1510159241.1215
  1292. Variable: MACRO_DEPTH
  1293. Value: 1
  1294.  
  1295.  
  1296. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:378 ast_str_retrieve_variable: Result of 'ONETOUCH_RECFILE' is NULL
  1297. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:708 pbx_substitute_variables_helper_full: Function CDR(recordingfile) result is ''
  1298. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:777 pbx_substitute_variables_helper_full: Expression result is '0'
  1299. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:378 ast_str_retrieve_variable: Result of 'ONETOUCH_RECFILE' is NULL
  1300. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx.c:2875 pbx_extension_helper: Launching 'ExecIf'
  1301.     -- Executing [s@macro-hangupcall:3] ExecIf("IAX2/222-9806", "0?Set(CDR(recordingfile)=)") in new stack
  1302. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1303. Event: Newexten
  1304. Privilege: call,all
  1305. Channel: IAX2/222-9806
  1306. ChannelState: 7
  1307. ChannelStateDesc: Busy
  1308. CallerIDNum: 222
  1309. CallerIDName: Roy
  1310. ConnectedLineNum: <unknown>
  1311. ConnectedLineName: <unknown>
  1312. Language: en
  1313. AccountCode:
  1314. Context: macro-hangupcall
  1315. Exten: s
  1316. Priority: 3
  1317. Uniqueid: 1510159241.1215
  1318. Linkedid: 1510159241.1215
  1319. Extension: s
  1320. Application: ExecIf
  1321. AppData: 0?Set(CDR(recordingfile)=)
  1322.  
  1323.  
  1324. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1325. Event: Newexten
  1326. Privilege: call,all
  1327. Channel: IAX2/222-9806
  1328. ChannelState: 7
  1329. ChannelStateDesc: Busy
  1330. CallerIDNum: 222
  1331. CallerIDName: Roy
  1332. ConnectedLineNum: <unknown>
  1333. ConnectedLineName: <unknown>
  1334. Language: en
  1335. AccountCode:
  1336. Context: macro-hangupcall
  1337. Exten: s
  1338. Priority: 3
  1339. Uniqueid: 1510159241.1215
  1340. Linkedid: 1510159241.1215
  1341. Extension: s
  1342. Application: ExecIf
  1343. AppData: 0?Set(CDR(recordingfile)=)
  1344.  
  1345.  
  1346. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: app_macro.c:459 _macro_exec: Executed application: ExecIf
  1347. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:474 ast_str_substitute_variables_full: Evaluating 'ONETOUCH_RECFILE' (from 'ONETOUCH_RECFILE}"!="" & "${CDR(recordingfile)}"=""' len 16)
  1348. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:378 ast_str_retrieve_variable: Result of 'ONETOUCH_RECFILE' is NULL
  1349. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:474 ast_str_substitute_variables_full: Evaluating 'CDR(recordingfile)' (from 'CDR(recordingfile)}"=""' len 18)
  1350. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:508 ast_str_substitute_variables_full: Function CDR(recordingfile) result is ''
  1351. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:566 ast_str_substitute_variables_full: Expression result is '0'
  1352. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:474 ast_str_substitute_variables_full: Evaluating 'ONETOUCH_RECFILE' (from 'ONETOUCH_RECFILE})' len 16)
  1353. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx_variables.c:378 ast_str_retrieve_variable: Result of 'ONETOUCH_RECFILE' is NULL
  1354. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1355. Event: VarSet
  1356. Privilege: dialplan,all
  1357. Channel: IAX2/222-9806
  1358. ChannelState: 7
  1359. ChannelStateDesc: Busy
  1360. CallerIDNum: 222
  1361. CallerIDName: Roy
  1362. ConnectedLineNum: <unknown>
  1363. ConnectedLineName: <unknown>
  1364. Language: en
  1365. AccountCode:
  1366. Context: macro-hangupcall
  1367. Exten: s
  1368. Priority: 3
  1369. Uniqueid: 1510159241.1215
  1370. Linkedid: 1510159241.1215
  1371. Variable: MACRO_DEPTH
  1372. Value: 1
  1373.  
  1374.  
  1375. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1376. Event: VarSet
  1377. Privilege: dialplan,all
  1378. Channel: IAX2/222-9806
  1379. ChannelState: 7
  1380. ChannelStateDesc: Busy
  1381. CallerIDNum: 222
  1382. CallerIDName: Roy
  1383. ConnectedLineNum: <unknown>
  1384. ConnectedLineName: <unknown>
  1385. Language: en
  1386. AccountCode:
  1387. Context: macro-hangupcall
  1388. Exten: s
  1389. Priority: 3
  1390. Uniqueid: 1510159241.1215
  1391. Linkedid: 1510159241.1215
  1392. Variable: MACRO_DEPTH
  1393. Value: 1
  1394.  
  1395.  
  1396. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx.c:2875 pbx_extension_helper: Launching 'Hangup'
  1397.     -- Executing [s@macro-hangupcall:4] Hangup("IAX2/222-9806", "") in new stack
  1398. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1399. Event: Newexten
  1400. Privilege: call,all
  1401. Channel: IAX2/222-9806
  1402. ChannelState: 7
  1403. ChannelStateDesc: Busy
  1404. CallerIDNum: 222
  1405. CallerIDName: Roy
  1406. ConnectedLineNum: <unknown>
  1407. ConnectedLineName: <unknown>
  1408. Language: en
  1409. AccountCode:
  1410. Context: macro-hangupcall
  1411. Exten: s
  1412. Priority: 4
  1413. Uniqueid: 1510159241.1215
  1414. Linkedid: 1510159241.1215
  1415. Extension: s
  1416. Application: Hangup
  1417. AppData:
  1418.  
  1419.  
  1420. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1421. Event: Newexten
  1422. Privilege: call,all
  1423. Channel: IAX2/222-9806
  1424. ChannelState: 7
  1425. ChannelStateDesc: Busy
  1426. CallerIDNum: 222
  1427. CallerIDName: Roy
  1428. ConnectedLineNum: <unknown>
  1429. ConnectedLineName: <unknown>
  1430. Language: en
  1431. AccountCode:
  1432. Context: macro-hangupcall
  1433. Exten: s
  1434. Priority: 4
  1435. Uniqueid: 1510159241.1215
  1436. Linkedid: 1510159241.1215
  1437. Extension: s
  1438. Application: Hangup
  1439. AppData:
  1440.  
  1441.  
  1442. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: channel.c:2579 ast_softhangup_nolock: Soft-Hanging (0x20) up channel 'IAX2/222-9806'
  1443. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: app_macro.c:453 _macro_exec: Spawn extension (macro-hangupcall,s,4) exited non-zero on 'IAX2/222-9806' in macro 'hangupcall'
  1444.   == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'IAX2/222-9806' in macro 'hangupcall'
  1445. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1446. Event: VarSet
  1447. Privilege: dialplan,all
  1448. Channel: IAX2/222-9806
  1449. ChannelState: 7
  1450. ChannelStateDesc: Busy
  1451. CallerIDNum: 222
  1452. CallerIDName: Roy
  1453. ConnectedLineNum: <unknown>
  1454. ConnectedLineName: <unknown>
  1455. Language: en
  1456. AccountCode:
  1457. Context: macro-hangupcall
  1458. Exten: s
  1459. Priority: 4
  1460. Uniqueid: 1510159241.1215
  1461. Linkedid: 1510159241.1215
  1462. Variable: MACRO_DEPTH
  1463. Value: 0
  1464.  
  1465.  
  1466. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1467. Event: VarSet
  1468. Privilege: dialplan,all
  1469. Channel: IAX2/222-9806
  1470. ChannelState: 7
  1471. ChannelStateDesc: Busy
  1472. CallerIDNum: 222
  1473. CallerIDName: Roy
  1474. ConnectedLineNum: <unknown>
  1475. ConnectedLineName: <unknown>
  1476. Language: en
  1477. AccountCode:
  1478. Context: macro-hangupcall
  1479. Exten: s
  1480. Priority: 4
  1481. Uniqueid: 1510159241.1215
  1482. Linkedid: 1510159241.1215
  1483. Variable: MACRO_DEPTH
  1484. Value: 0
  1485.  
  1486.  
  1487. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1488. Event: VarSet
  1489. Privilege: dialplan,all
  1490. Channel: IAX2/222-9806
  1491. ChannelState: 7
  1492. ChannelStateDesc: Busy
  1493. CallerIDNum: 222
  1494. CallerIDName: Roy
  1495. ConnectedLineNum: <unknown>
  1496. ConnectedLineName: <unknown>
  1497. Language: en
  1498. AccountCode:
  1499. Context: macro-hangupcall
  1500. Exten: s
  1501. Priority: 4
  1502. Uniqueid: 1510159241.1215
  1503. Linkedid: 1510159241.1215
  1504. Variable: MACRO_EXTEN
  1505. Value:
  1506.  
  1507.  
  1508. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1509. Event: VarSet
  1510. Privilege: dialplan,all
  1511. Channel: IAX2/222-9806
  1512. ChannelState: 7
  1513. ChannelStateDesc: Busy
  1514. CallerIDNum: 222
  1515. CallerIDName: Roy
  1516. ConnectedLineNum: <unknown>
  1517. ConnectedLineName: <unknown>
  1518. Language: en
  1519. AccountCode:
  1520. Context: macro-hangupcall
  1521. Exten: s
  1522. Priority: 4
  1523. Uniqueid: 1510159241.1215
  1524. Linkedid: 1510159241.1215
  1525. Variable: MACRO_EXTEN
  1526. Value:
  1527.  
  1528.  
  1529. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1530. Event: VarSet
  1531. Privilege: dialplan,all
  1532. Channel: IAX2/222-9806
  1533. ChannelState: 7
  1534. ChannelStateDesc: Busy
  1535. CallerIDNum: 222
  1536. CallerIDName: Roy
  1537. ConnectedLineNum: <unknown>
  1538. ConnectedLineName: <unknown>
  1539. Language: en
  1540. AccountCode:
  1541. Context: macro-hangupcall
  1542. Exten: s
  1543. Priority: 4
  1544. Uniqueid: 1510159241.1215
  1545. Linkedid: 1510159241.1215
  1546. Variable: MACRO_CONTEXT
  1547. Value:
  1548.  
  1549.  
  1550. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1551. Event: VarSet
  1552. Privilege: dialplan,all
  1553. Channel: IAX2/222-9806
  1554. ChannelState: 7
  1555. ChannelStateDesc: Busy
  1556. CallerIDNum: 222
  1557. CallerIDName: Roy
  1558. ConnectedLineNum: <unknown>
  1559. ConnectedLineName: <unknown>
  1560. Language: en
  1561. AccountCode:
  1562. Context: macro-hangupcall
  1563. Exten: s
  1564. Priority: 4
  1565. Uniqueid: 1510159241.1215
  1566. Linkedid: 1510159241.1215
  1567. Variable: MACRO_CONTEXT
  1568. Value:
  1569.  
  1570.  
  1571. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1572. Event: VarSet
  1573. Privilege: dialplan,all
  1574. Channel: IAX2/222-9806
  1575. ChannelState: 7
  1576. ChannelStateDesc: Busy
  1577. CallerIDNum: 222
  1578. CallerIDName: Roy
  1579. ConnectedLineNum: <unknown>
  1580. ConnectedLineName: <unknown>
  1581. Language: en
  1582. AccountCode:
  1583. Context: macro-hangupcall
  1584. Exten: s
  1585. Priority: 4
  1586. Uniqueid: 1510159241.1215
  1587. Linkedid: 1510159241.1215
  1588. Variable: MACRO_PRIORITY
  1589. Value:
  1590.  
  1591.  
  1592. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1593. Event: VarSet
  1594. Privilege: dialplan,all
  1595. Channel: IAX2/222-9806
  1596. ChannelState: 7
  1597. ChannelStateDesc: Busy
  1598. CallerIDNum: 222
  1599. CallerIDName: Roy
  1600. ConnectedLineNum: <unknown>
  1601. ConnectedLineName: <unknown>
  1602. Language: en
  1603. AccountCode:
  1604. Context: macro-hangupcall
  1605. Exten: s
  1606. Priority: 4
  1607. Uniqueid: 1510159241.1215
  1608. Linkedid: 1510159241.1215
  1609. Variable: MACRO_PRIORITY
  1610. Value:
  1611.  
  1612.  
  1613. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: pbx.c:4157 ast_pbx_h_exten_run: Spawn extension (from-internal,h,1) exited non-zero on 'IAX2/222-9806'
  1614.   == Spawn extension (from-internal, h, 1) exited non-zero on 'IAX2/222-9806'
  1615. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: channel.c:2728 ast_hangup: Hanging up channel 'IAX2/222-9806'
  1616. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:5318 iax2_hangup: We're hanging up IAX2/222-9806 now...
  1617. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1618. Event: HangupRequest
  1619. Privilege: call,all
  1620. Channel: IAX2/222-9806
  1621. ChannelState: 7
  1622. ChannelStateDesc: Busy
  1623. CallerIDNum: 222
  1624. CallerIDName: Roy
  1625. ConnectedLineNum: <unknown>
  1626. ConnectedLineName: <unknown>
  1627. Language: en
  1628. AccountCode:
  1629. Context: from-internal
  1630. Exten: h
  1631. Priority: 1
  1632. Uniqueid: 1510159241.1215
  1633. Linkedid: 1510159241.1215
  1634.  
  1635.  
  1636. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1637. Event: HangupRequest
  1638. Privilege: call,all
  1639. Channel: IAX2/222-9806
  1640. ChannelState: 7
  1641. ChannelStateDesc: Busy
  1642. CallerIDNum: 222
  1643. CallerIDName: Roy
  1644. ConnectedLineNum: <unknown>
  1645. ConnectedLineName: <unknown>
  1646. Language: en
  1647. AccountCode:
  1648. Context: from-internal
  1649. Exten: h
  1650. Priority: 1
  1651. Uniqueid: 1510159241.1215
  1652. Linkedid: 1510159241.1215
  1653.  
  1654.  
  1655. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:5335 iax2_hangup: Really destroying IAX2/222-9806 now...
  1656. [2017-11-08 10:40:48] DEBUG[2188][C-00000085]: chan_iax2.c:3083 sched_delay_remove: schedule decrement of callno used for 192.168.10.53 in 60 seconds
  1657.     -- Hungup 'IAX2/222-9806'
  1658. [2017-11-08 10:40:48] DEBUG[2213]: res_odbc.c:865 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f6fc8060970 from class 'asteriskcdrdb'
  1659. [2017-11-08 10:40:48] DEBUG[2213]: cel_odbc.c:766 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,extra) VALUES ('HANGUP',{ts '2017-11-08 10:40:48.974020'},'Roy','222','222','','8604000023','h','from-internal','IAX2/222-9806','','',3,'','1510159241.1215','1510159241.1215','','','{"hangupcause":16,"dialstatus":"","hangupsource":"IAX2/222-9806"}')]
  1660. [2017-11-08 10:40:48] DEBUG[2213]: res_odbc.c:714 ast_odbc_release_obj: Releasing ODBC handle 0x7f6fc8060970 into pool
  1661. [2017-11-08 10:40:48] DEBUG[2213]: cel_radius.c:199 radius_log: Unable to create RADIUS record. CEL not recorded!
  1662. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1663. Event: Hangup
  1664. Privilege: call,all
  1665. Channel: IAX2/222-9806
  1666. ChannelState: 7
  1667. ChannelStateDesc: Busy
  1668. CallerIDNum: 222
  1669. CallerIDName: Roy
  1670. ConnectedLineNum: <unknown>
  1671. ConnectedLineName: <unknown>
  1672. Language: en
  1673. AccountCode:
  1674. Context: from-internal
  1675. Exten: h
  1676. Priority: 1
  1677. Uniqueid: 1510159241.1215
  1678. Linkedid: 1510159241.1215
  1679. Cause: 16
  1680. Cause-txt: Normal Clearing
  1681.  
  1682.  
  1683. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1684. Event: Hangup
  1685. Privilege: call,all
  1686. Channel: IAX2/222-9806
  1687. ChannelState: 7
  1688. ChannelStateDesc: Busy
  1689. CallerIDNum: 222
  1690. CallerIDName: Roy
  1691. ConnectedLineNum: <unknown>
  1692. ConnectedLineName: <unknown>
  1693. Language: en
  1694. AccountCode:
  1695. Context: from-internal
  1696. Exten: h
  1697. Priority: 1
  1698. Uniqueid: 1510159241.1215
  1699. Linkedid: 1510159241.1215
  1700. Cause: 16
  1701. Cause-txt: Normal Clearing
  1702.  
  1703.  
  1704. [2017-11-08 10:40:48] DEBUG[2209]: cdr.c:3279 post_cdr: Skipping CDR  for IAX2/222-9806 since we weren't answered
  1705. [2017-11-08 10:40:48] DEBUG[2213]: res_odbc.c:865 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f6fc8060970 from class 'asteriskcdrdb'
  1706. [2017-11-08 10:40:48] DEBUG[2213]: cel_odbc.c:766 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,extra) VALUES ('CHAN_END',{ts '2017-11-08 10:40:48.977243'},'Roy','222','222','','8604000023','h','from-internal','IAX2/222-9806','','',3,'','1510159241.1215','1510159241.1215','','','')]
  1707. [2017-11-08 10:40:48] DEBUG[2213]: res_odbc.c:714 ast_odbc_release_obj: Releasing ODBC handle 0x7f6fc8060970 into pool
  1708. [2017-11-08 10:40:48] DEBUG[2213]: cel_radius.c:199 radius_log: Unable to create RADIUS record. CEL not recorded!
  1709. [2017-11-08 10:40:48] DEBUG[2213]: res_odbc.c:865 _ast_odbc_request_obj2: Reusing ODBC handle 0x7f6fc8060970 from class 'asteriskcdrdb'
  1710. [2017-11-08 10:40:48] DEBUG[2213]: cel_odbc.c:766 odbc_log: Executing SQL statement: [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,extra) VALUES ('LINKEDID_END',{ts '2017-11-08 10:40:48.979331'},'Roy','222','222','','8604000023','h','from-internal','IAX2/222-9806','','',3,'','1510159241.1215','1510159241.1215','','','')]
  1711. [2017-11-08 10:40:48] DEBUG[2213]: res_odbc.c:714 ast_odbc_release_obj: Releasing ODBC handle 0x7f6fc8060970 into pool
  1712. [2017-11-08 10:40:48] DEBUG[2213]: cel_radius.c:199 radius_log: Unable to create RADIUS record. CEL not recorded!
  1713. [2017-11-08 10:40:48] DEBUG[2184]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for IAX2 - 222
  1714. [2017-11-08 10:40:48] DEBUG[2184]: chan_iax2.c:14492 iax2_devicestate: Checking device state for device 222
  1715. [2017-11-08 10:40:48] DEBUG[2184]: chan_iax2.c:14501 iax2_devicestate: Found peer. What's device state of 222? addr=192.168.10.53:4569, defaddr=(null) maxms=2000, lastms=3
  1716. [2017-11-08 10:40:48] DEBUG[2184]: devicestate.c:474 do_state_change: Changing state for IAX2/222 - state 0 (Unknown)
  1717. [2017-11-08 10:40:48] DEBUG[2346]: app_queue.c:2491 device_state_cb: Device 'IAX2/222' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
  1718. [2017-11-08 10:40:48] DEBUG[2211]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for IAX2 - 222
  1719. [2017-11-08 10:40:48] DEBUG[2211]: chan_iax2.c:14492 iax2_devicestate: Checking device state for device 222
  1720. [2017-11-08 10:40:48] DEBUG[2211]: chan_iax2.c:14501 iax2_devicestate: Found peer. What's device state of 222? addr=192.168.10.53:4569, defaddr=(null) maxms=2000, lastms=3
  1721. [2017-11-08 10:40:48] DEBUG[2211]: devicestate.c:365 _ast_device_state: Checking if I can find provider for "Custom" - number: DND222
  1722. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1723. Event: DeviceStateChange
  1724. Privilege: call,all
  1725. Device: IAX2/222
  1726. State: UNKNOWN
  1727.  
  1728.  
  1729. [2017-11-08 10:40:48] DEBUG[2211]: devicestate.c:454 getproviderstate: Checking provider SLA with Custom
  1730. [2017-11-08 10:40:48] DEBUG[2211]: devicestate.c:454 getproviderstate: Checking provider Meetme with Custom
  1731. [2017-11-08 10:40:48] DEBUG[2211]: devicestate.c:454 getproviderstate: Checking provider Custom with Custom
  1732. [2017-11-08 10:40:48] DEBUG[2211]: db.c:376 db_get_common: Unable to find key 'DND222' in family 'CustomDevstate'
  1733. [2017-11-08 10:40:48] DEBUG[2434]: manager.c:5861 match_filter: Examining AMI event:
  1734. Event: ExtensionStatus
  1735. Privilege: call,all
  1736. Exten: 222
  1737. Context: ext-local
  1738. Hint: IAX2/222&Custom:DND222,CustomPresence:222
  1739. Status: 0
  1740. StatusText: Idle
  1741.  
  1742.  
  1743. [2017-11-08 10:40:48] DEBUG[2211]: app_queue.c:2566 extension_state_cb: Extension '222@ext-local' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
  1744. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1745. Event: DeviceStateChange
  1746. Privilege: call,all
  1747. Device: IAX2/222
  1748. State: UNKNOWN
  1749.  
  1750.  
  1751. [2017-11-08 10:40:48] DEBUG[12480]: manager.c:5861 match_filter: Examining AMI event:
  1752. Event: ExtensionStatus
  1753. Privilege: call,all
  1754. Exten: 222
  1755. Context: ext-local
  1756. Hint: IAX2/222&Custom:DND222,CustomPresence:222
  1757. Status: 0
  1758. StatusText: Idle
  1759.  
  1760.  
  1761. [2017-11-08 10:40:51] DEBUG[2329]: chan_sip.c:8996 __sip_alloc: Allocating new SIP dialog for 5e51220f1820eafc7cb0f59a0715804d@192.168.10.248:5160 - OPTIONS (No RTP)
  1762. [2017-11-08 10:40:51] DEBUG[2329]: acl.c:957 ast_ouraddrfor: For destination '208.100.39.55', our source address is '192.168.10.248'.
  1763. [2017-11-08 10:40:51] DEBUG[2329]: chan_sip.c:3910 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.10.248:5160
  1764. [2017-11-08 10:40:51] DEBUG[2329]: chan_sip.c:8781 change_callid_pvt: SIP call-id changed from '5e51220f1820eafc7cb0f59a0715804d@192.168.10.248:5160' to '509e5d2e04636db81886d5965c338666@192.168.10.248:5160'
  1765. [2017-11-08 10:40:51] DEBUG[2329]: chan_sip.c:3396 initialize_initreq: Initializing initreq for method OPTIONS - callid 509e5d2e04636db81886d5965c338666@192.168.10.248:5160
  1766. [2017-11-08 10:40:51] DEBUG[2329]: chan_sip.c:3753 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 208.100.39.55:5080
  1767. freepbx*CLI> exit
  1768. Asterisk cleanly ending (0).
  1769. Executing last minute cleanups
  1770. [root@freepbx ~]#
  1771.  

Reply to "call2"

Here you can reply to the paste above