From Joy Garcia, 2 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: cornflowerblue; font-weight: bold;"> 2017-02-28 19:49:20.617107 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/+18024488966@sip.nexmo.com [a2575d08-a1af-45da-b18f-a25da500da55]
  2. 2017-02-28 19:49:20.617107 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+18024488966@sip.nexmo.com) Running State Change CS_NEW (Cur 1 Tot 100)
  3. 2017-02-28 19:49:20.617107 [DEBUG] sofia.c:9815 sofia/internal/+18024488966@sip.nexmo.com receiving invite from 173.193.199.24:5060 version: 1.6.14 git a8d53fd 2017-01-12 17:48:02Z 32bit
  4. 2017-02-28 19:49:20.617107 [DEBUG] sofia.c:9927 IP 173.193.199.24 Approved by acl "nexmo[]". Access Granted.
  5. 2017-02-28 19:49:20.637083 [DEBUG] sofia.c:7041 Channel sofia/internal/+18024488966@sip.nexmo.com entering state [received][100]
  6. 2017-02-28 19:49:20.637083 [DEBUG] sofia.c:7051 Remote SDP:
  7. v=0
  8. o=Nexmo 967708594 967708594 IN IP4 169.54.104.168
  9. s=Nexmo
  10. c=IN IP4 169.54.104.168
  11. t=0 0
  12. m=audio 14214 RTP/AVP 8 0 97 18 9 117 101
  13. a=rtpmap:8 PCMA/8000
  14. a=rtpmap:0 PCMU/8000
  15. a=rtpmap:97 iLBC/8000
  16. a=fmtp:97 mode=30
  17. a=rtpmap:18 G729/8000
  18. a=fmtp:18 annexb=no
  19. a=rtpmap:9 G722/8000
  20. a=rtpmap:117 speex/16000
  21. a=rtpmap:101 telephone-event/8000
  22. a=fmtp:101 0-16
  23. a=ptime:20
  24.  
  25. 2017-02-28 19:49:20.637083 [DEBUG] sofia.c:7429 (sofia/internal/+18024488966@sip.nexmo.com) State Change CS_NEW -> CS_INIT
  26. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/+18024488966@sip.nexmo.com) State NEW
  27. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+18024488966@sip.nexmo.com) Running State Change CS_INIT (Cur 1 Tot 100)
  28. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/+18024488966@sip.nexmo.com) State INIT
  29. 2017-02-28 19:49:20.637083 [DEBUG] mod_sofia.c:90 sofia/internal/+18024488966@sip.nexmo.com SOFIA INIT
  30. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:40 sofia/internal/+18024488966@sip.nexmo.com Standard INIT
  31. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/+18024488966@sip.nexmo.com) State Change CS_INIT -> CS_ROUTING
  32. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/+18024488966@sip.nexmo.com) State INIT going to sleep
  33. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+18024488966@sip.nexmo.com) Running State Change CS_ROUTING (Cur 1 Tot 100)
  34. 2017-02-28 19:49:20.637083 [DEBUG] switch_channel.c:2249 (sofia/internal/+18024488966@sip.nexmo.com) Callstate Change DOWN -> RINGING
  35. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/+18024488966@sip.nexmo.com) State ROUTING
  36. 2017-02-28 19:49:20.637083 [DEBUG] mod_sofia.c:143 sofia/internal/+18024488966@sip.nexmo.com SOFIA ROUTING
  37. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:236 sofia/internal/+18024488966@sip.nexmo.com Standard ROUTING
  38. 2017-02-28 19:49:20.637083 [INFO] mod_dialplan_xml.c:637 Processing +18024488966 <+18024488966>->1000 in context public
  39. Dialplan: sofia/internal/+18024488966@sip.nexmo.com parsing [public->unloop] continue=false
  40. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  41. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  42. Dialplan: sofia/internal/+18024488966@sip.nexmo.com parsing [public->outside_call] continue=true
  43. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Absolute Condition [outside_call]
  44. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Action set(outside_call=true)
  45. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  46. Dialplan: sofia/internal/+18024488966@sip.nexmo.com parsing [public->call_debug] continue=true
  47. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  48. Dialplan: sofia/internal/+18024488966@sip.nexmo.com parsing [public->nexmo_1000] continue=false
  49. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Regex (PASS) [nexmo_1000] destination_number(1000) =~ /^1000$/ break=on-false
  50. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Action info()
  51. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Action answer()
  52. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Action playback(silence_stream://2000)
  53. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Action rxfax(/tmp/FAX-${uuid}.tif)
  54. Dialplan: sofia/internal/+18024488966@sip.nexmo.com Action hangup()
  55. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/+18024488966@sip.nexmo.com) State Change CS_ROUTING -> CS_EXECUTE
  56. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/+18024488966@sip.nexmo.com) State ROUTING going to sleep
  57. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+18024488966@sip.nexmo.com) Running State Change CS_EXECUTE (Cur 1 Tot 100)
  58. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/+18024488966@sip.nexmo.com) State EXECUTE
  59. 2017-02-28 19:49:20.637083 [DEBUG] mod_sofia.c:198 sofia/internal/+18024488966@sip.nexmo.com SOFIA EXECUTE
  60. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_state_machine.c:328 sofia/internal/+18024488966@sip.nexmo.com Standard EXECUTE
  61. EXECUTE sofia/internal/+18024488966@sip.nexmo.com set(outside_call=true)
  62. 2017-02-28 19:49:20.637083 [DEBUG] mod_dptools.c:1527 SET sofia/internal/+18024488966@sip.nexmo.com [outside_call]=[true]
  63. EXECUTE sofia/internal/+18024488966@sip.nexmo.com export(RFC2822_DATE=Tue, 28 Feb 2017 19:49:20 +0000)
  64. 2017-02-28 19:49:20.637083 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Tue, 28 Feb 2017 19:49:20 +0000]
  65. EXECUTE sofia/internal/+18024488966@sip.nexmo.com answer()
  66. 2017-02-28 19:49:20.637083 [DEBUG] mod_sofia.c:817 Disabling proxy mode due to call answer with no bridge
  67. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  68. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  69. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  70. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  71. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  72. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  73. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  74. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  75. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  76. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  77. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [iLBC:97:8000:20:0:1]/[opus:116:48000:20:0:1]
  78. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [iLBC:97:8000:20:0:1]/[G722:9:8000:20:64000:1]
  79. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  80. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  81. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
  82. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  83. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  84. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  85. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
  86. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  87. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  88. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  89. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  90. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:117:16000:20:0:1]/[opus:116:48000:20:0:1]
  91. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:117:16000:20:0:1]/[G722:9:8000:20:64000:1]
  92. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:117:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
  93. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:117:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
  94. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4294 Set telephone-event payload to 101@8000
  95. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:3043 Set Codec sofia/internal/+18024488966@sip.nexmo.com PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  96. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_codec.c:111 sofia/internal/+18024488966@sip.nexmo.com Original read codec set to PCMA:8
  97. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4637 Set telephone-event payload to 101@8000
  98. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:4696 sofia/internal/+18024488966@sip.nexmo.com Set 2833 dtmf send payload to 101 recv payload to 101
  99. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:6703 AUDIO RTP [sofia/internal/+18024488966@sip.nexmo.com] 138.197.209.147 port 25048 -> 169.54.104.168 port 14214 codec: 8 ms: 20
  100. 2017-02-28 19:49:20.637083 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 160 bytes per 20ms
  101. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:7009 sofia/internal/+18024488966@sip.nexmo.com Set 2833 dtmf send payload to 101
  102. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:7016 sofia/internal/+18024488966@sip.nexmo.com Set 2833 dtmf receive payload to 101
  103. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:7039 sofia/internal/+18024488966@sip.nexmo.com Set rtp dtmf delay to 40
  104. 2017-02-28 19:49:20.637083 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/+18024488966@sip.nexmo.com!
  105. 2017-02-28 19:49:20.637083 [DEBUG] switch_channel.c:3473 (sofia/internal/+18024488966@sip.nexmo.com) Callstate Change RINGING -> EARLY
  106. 2017-02-28 19:49:20.637083 [DEBUG] switch_core_media.c:6686 Audio params are unchanged for sofia/internal/+18024488966@sip.nexmo.com.
  107. 2017-02-28 19:49:20.637083 [DEBUG] mod_sofia.c:849 Local SDP sofia/internal/+18024488966@sip.nexmo.com:
  108. v=0
  109. o=FreeSWITCH 1488286312 1488286313 IN IP4 138.197.209.147
  110. s=FreeSWITCH
  111. c=IN IP4 138.197.209.147
  112. t=0 0
  113. m=audio 25048 RTP/AVP 8 101
  114. a=rtpmap:8 PCMA/8000
  115. a=rtpmap:101 telephone-event/8000
  116. a=fmtp:101 0-16
  117. a=ptime:20
  118. a=sendrecv
  119.  
  120. 2017-02-28 19:49:20.637083 [DEBUG] sofia.c:7041 Channel sofia/internal/+18024488966@sip.nexmo.com entering state [completed][200]
  121. 2017-02-28 19:49:20.637083 [NOTICE] mod_dptools.c:1309 Channel [sofia/internal/+18024488966@sip.nexmo.com] has been answered
  122. 2017-02-28 19:49:20.637083 [DEBUG] switch_channel.c:3772 (sofia/internal/+18024488966@sip.nexmo.com) Callstate Change EARLY -> ACTIVE
  123. EXECUTE sofia/internal/+18024488966@sip.nexmo.com playback(silence_stream://2000)
  124. 2017-02-28 19:49:20.637083 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
  125. 2017-02-28 19:49:20.737114 [DEBUG] sofia.c:7041 Channel sofia/internal/+18024488966@sip.nexmo.com entering state [ready][200]
  126. 2017-02-28 19:49:21.117142 [DEBUG] switch_rtp.c:6994 Correct audio ip/port confirmed.
  127. 2017-02-28 19:49:22.637084 [DEBUG] switch_ivr_play_say.c:1942 done playing file silence_stream://2000
  128. EXECUTE sofia/internal/+18024488966@sip.nexmo.com rxfax(/tmp/FAX-a2575d08-a1af-45da-b18f-a25da500da55.tif)
  129. 2017-02-28 19:49:22.637084 [DEBUG] mod_spandsp_fax.c:1446 Raw read codec activation Success L16 20000
  130. 2017-02-28 19:49:22.637084 [DEBUG] switch_core_codec.c:223 sofia/internal/+18024488966@sip.nexmo.com Push codec L16:100
  131. 2017-02-28 19:49:22.637084 [DEBUG] mod_spandsp_fax.c:1464 Raw write codec activation Success L16
  132. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase A_CED, state ANSWERING
  133. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Starting answer mode
  134. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase A_CED to B_TX
  135. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  136. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
  137. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  138. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state ANSWERING to R
  139. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Sending ident 'SpanDSP Fax Ident'
  140. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  CSI without final frame tag
  141. 2017-02-28 19:49:25.717083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 03 40 74 6e 65 64 49 20 78 61 46 20 50 53 44 6e 61 70 53 20 20 20
  142. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  143. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DIS:
  144. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Store and forward Internet fax (T.37): Not set
  145. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Real-time Internet fax (T.38): Not set
  146. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= 3G mobile network: Not set
  147. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= V.8 capabilities: Not set
  148. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Preferred octets: 256 octets
  149. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Ready to transmit a fax document (polling): Not set
  150. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..1.= Can receive fax: Set
  151. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17
  152. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
  153. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= 2-D coding: Set
  154. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1%
  155. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 10..= Recording length: Unlimited
  156. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85
  157. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  158. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Compressed/uncompressed mode: Compressed
  159. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .1..= Error correction mode (ECM): ECM
  160. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= T.6 coding: Set
  161. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  162. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= "Field not valid" supported: Not set
  163. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Multiple selective polling: Not set
  164. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Polled sub-address: Not set
  165. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= T.43 coding: Not set
  166. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Plane interleave: Not set
  167. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
  168. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Reserved for the use of extended voice coding set: Not set
  169. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  170. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...1= R8x15.4lines/mm: Set
  171. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= 300x300pels/25.4mm: Not set
  172. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set
  173. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 1...= Inch-based resolution preferred: Set
  174. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...1 ....= Metric-based resolution preferred: Set
  175. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
  176. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Selective polling: Not set
  177. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  178. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Sub-addressing: Not set
  179. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Password: Not set
  180. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Ready to transmit a data file (polling): Not set
  181. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Binary file transfer (BFT): Not set
  182. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Document transfer mode (DTM): Not set
  183. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Electronic data interchange (EDI): Not set
  184. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  185. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Basic transfer mode (BTM): Not set
  186. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Ready to transfer a character or mixed mode document (polling): Not set
  187. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= Character mode: Not set
  188. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Mixed mode (Annex E/T.4): Not set
  189. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  190. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Processable mode 26 (Rec. T.505): Not set
  191. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Digital network capability: Not set
  192. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Duplex capability: Half only
  193. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= JPEG coding: Not set
  194. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Full colour mode: Not set
  195. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= 12bits/pel component: Not set
  196. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  197. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= No subsampling (1:1:1): Not set
  198. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Custom illuminant: Not set
  199. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Custom gamut range: Not set
  200. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 1...= North American Letter (215.9mm x 279.4mm): Set
  201. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...1 ....= North American Legal (215.9mm x 355.6mm): Set
  202. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..1. ....= Single-progression sequential coding (Rec. T.85) basic: Set
  203. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Set
  204. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   0... ....= Extension indicator: Not set
  205. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  DIS with final frame tag
  206. 2017-02-28 19:49:27.297146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 80 00 ee fa c4 80 9d 80 80 80 78
  207. 2017-02-28 19:49:27.757088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  208. 2017-02-28 19:49:27.837087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  209. 2017-02-28 19:49:27.837087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_TX to B_RX
  210. 2017-02-28 19:49:27.837087 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
  211. 2017-02-28 19:49:27.837087 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  212. 2017-02-28 19:49:27.837087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4
  213. 2017-02-28 19:49:28.617105 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state R
  214. 2017-02-28 19:49:28.817107 [DEBUG] sofia.c:7041 Channel sofia/internal/+18024488966@sip.nexmo.com entering state [received][100]
  215. 2017-02-28 19:49:28.817107 [DEBUG] sofia.c:7051 Remote SDP:
  216. v=0
  217. o=Nexmo 967708594 967708595 IN IP4 169.54.104.168
  218. s=Nexmo
  219. c=IN IP4 169.54.104.168
  220. t=0 0
  221. m=image 4557 udptl t38
  222. c=IN IP4 169.54.104.168
  223. a=T38FaxVersion:0
  224. a=T38MaxBitRate:14400
  225. a=T38FaxRateManagement:transferredTCF
  226. a=T38FaxMaxDatagram:89
  227. a=T38FaxUdpEC:t38UDPFEC
  228.  
  229. 2017-02-28 19:49:28.817107 [DEBUG] switch_core_media.c:3950 sofia/internal/+18024488966@sip.nexmo.com T38 REFUSE on request
  230. 2017-02-28 19:49:28.817107 [DEBUG] sofia.c:7946 Reinvite resulted in codec negotiation failure.
  231. 2017-02-28 19:49:28.817107 [DEBUG] sofia.c:7034 Channel sofia/internal/+18024488966@sip.nexmo.com skipping state [ready][488]
  232. 2017-02-28 19:49:28.877132 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state R
  233. 2017-02-28 19:49:28.877132 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4-flagged
  234. 2017-02-28 19:49:28.917097 [DEBUG] sofia.c:7041 Channel sofia/internal/+18024488966@sip.nexmo.com entering state [received][100]
  235. 2017-02-28 19:49:28.917097 [DEBUG] sofia.c:7051 Remote SDP:
  236. v=0
  237. o=Nexmo 967708594 967708596 IN IP4 169.54.104.168
  238. s=Nexmo
  239. c=IN IP4 169.54.104.168
  240. t=0 0
  241. m=audio 14214 RTP/AVP 8 101
  242. a=rtpmap:8 PCMA/8000
  243. a=rtpmap:101 telephone-event/8000
  244. a=fmtp:101 0-16
  245. a=ptime:20
  246.  
  247. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  248. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  249. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  250. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  251. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  252. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:4294 Set telephone-event payload to 101@8000
  253. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:4637 Set telephone-event payload to 101@8000
  254. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:4696 sofia/internal/+18024488966@sip.nexmo.com Set 2833 dtmf send payload to 101 recv payload to 101
  255. 2017-02-28 19:49:28.917097 [DEBUG] switch_core_media.c:6686 Audio params are unchanged for sofia/internal/+18024488966@sip.nexmo.com.
  256. 2017-02-28 19:49:28.917097 [DEBUG] sofia.c:7938 Processing updated SDP
  257. 2017-02-28 19:49:28.917097 [DEBUG] sofia.c:7041 Channel sofia/internal/+18024488966@sip.nexmo.com entering state [completed][200]
  258. 2017-02-28 19:49:28.997118 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Abort (-8) in state R
  259. 2017-02-28 19:49:28.997118 [DEBUG] sofia.c:7041 Channel sofia/internal/+18024488966@sip.nexmo.com entering state [ready][200]
  260. 2017-02-28 19:49:29.657104 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state R
  261. 2017-02-28 19:49:29.657104 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4-dropped
  262. 2017-02-28 19:49:29.837101 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 T4-dropped expired in phase B_RX, state R. The line is now quiet.
  263. 2017-02-28 19:49:29.837101 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Retry number 1
  264. 2017-02-28 19:49:29.837101 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_RX to B_TX
  265. 2017-02-28 19:49:29.837101 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  266. 2017-02-28 19:49:29.837101 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
  267. 2017-02-28 19:49:29.837101 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Sending ident 'SpanDSP Fax Ident'
  268. 2017-02-28 19:49:29.837101 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  CSI without final frame tag
  269. 2017-02-28 19:49:29.837101 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 03 40 74 6e 65 64 49 20 78 61 46 20 50 53 44 6e 61 70 53 20 20 20
  270. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  271. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DIS:
  272. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Store and forward Internet fax (T.37): Not set
  273. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Real-time Internet fax (T.38): Not set
  274. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= 3G mobile network: Not set
  275. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= V.8 capabilities: Not set
  276. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Preferred octets: 256 octets
  277. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Ready to transmit a fax document (polling): Not set
  278. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..1.= Can receive fax: Set
  279. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17
  280. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
  281. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= 2-D coding: Set
  282. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1%
  283. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 10..= Recording length: Unlimited
  284. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85
  285. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  286. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Compressed/uncompressed mode: Compressed
  287. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .1..= Error correction mode (ECM): ECM
  288. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= T.6 coding: Set
  289. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  290. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= "Field not valid" supported: Not set
  291. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Multiple selective polling: Not set
  292. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Polled sub-address: Not set
  293. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= T.43 coding: Not set
  294. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Plane interleave: Not set
  295. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
  296. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Reserved for the use of extended voice coding set: Not set
  297. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  298. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...1= R8x15.4lines/mm: Set
  299. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= 300x300pels/25.4mm: Not set
  300. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set
  301. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 1...= Inch-based resolution preferred: Set
  302. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...1 ....= Metric-based resolution preferred: Set
  303. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
  304. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Selective polling: Not set
  305. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  306. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Sub-addressing: Not set
  307. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Password: Not set
  308. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Ready to transmit a data file (polling): Not set
  309. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Binary file transfer (BFT): Not set
  310. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Document transfer mode (DTM): Not set
  311. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Electronic data interchange (EDI): Not set
  312. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  313. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Basic transfer mode (BTM): Not set
  314. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Ready to transfer a character or mixed mode document (polling): Not set
  315. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= Character mode: Not set
  316. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Mixed mode (Annex E/T.4): Not set
  317. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  318. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Processable mode 26 (Rec. T.505): Not set
  319. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Digital network capability: Not set
  320. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Duplex capability: Half only
  321. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= JPEG coding: Not set
  322. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Full colour mode: Not set
  323. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= 12bits/pel component: Not set
  324. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  325. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= No subsampling (1:1:1): Not set
  326. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Custom illuminant: Not set
  327. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Custom gamut range: Not set
  328. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 1...= North American Letter (215.9mm x 279.4mm): Set
  329. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...1 ....= North American Legal (215.9mm x 355.6mm): Set
  330. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..1. ....= Single-progression sequential coding (Rec. T.85) basic: Set
  331. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Set
  332. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   0... ....= Extension indicator: Not set
  333. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  DIS with final frame tag
  334. 2017-02-28 19:49:31.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 80 00 ee fa c4 80 9d 80 80 80 78
  335. 2017-02-28 19:49:31.897087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  336. 2017-02-28 19:49:31.977109 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  337. 2017-02-28 19:49:31.977109 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_TX to B_RX
  338. 2017-02-28 19:49:31.977109 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
  339. 2017-02-28 19:49:31.977109 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  340. 2017-02-28 19:49:31.977109 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4
  341. 2017-02-28 19:49:35.437088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Retry number 2
  342. 2017-02-28 19:49:35.437088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_RX to B_TX
  343. 2017-02-28 19:49:35.437088 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  344. 2017-02-28 19:49:35.437088 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
  345. 2017-02-28 19:49:35.437088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Sending ident 'SpanDSP Fax Ident'
  346. 2017-02-28 19:49:35.437088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  CSI without final frame tag
  347. 2017-02-28 19:49:35.437088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 03 40 74 6e 65 64 49 20 78 61 46 20 50 53 44 6e 61 70 53 20 20 20
  348. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  349. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DIS:
  350. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Store and forward Internet fax (T.37): Not set
  351. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Real-time Internet fax (T.38): Not set
  352. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= 3G mobile network: Not set
  353. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= V.8 capabilities: Not set
  354. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Preferred octets: 256 octets
  355. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Ready to transmit a fax document (polling): Not set
  356. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..1.= Can receive fax: Set
  357. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17
  358. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
  359. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= 2-D coding: Set
  360. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..10= Recording width: 215mm +- 1%, 255mm +- 1% and 303mm +- 1%
  361. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 10..= Recording length: Unlimited
  362. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85
  363. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  364. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Compressed/uncompressed mode: Compressed
  365. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .1..= Error correction mode (ECM): ECM
  366. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= T.6 coding: Set
  367. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  368. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= "Field not valid" supported: Not set
  369. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Multiple selective polling: Not set
  370. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Polled sub-address: Not set
  371. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= T.43 coding: Not set
  372. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Plane interleave: Not set
  373. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
  374. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Reserved for the use of extended voice coding set: Not set
  375. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  376. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...1= R8x15.4lines/mm: Set
  377. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= 300x300pels/25.4mm: Not set
  378. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .1..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Set
  379. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 1...= Inch-based resolution preferred: Set
  380. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...1 ....= Metric-based resolution preferred: Set
  381. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7
  382. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Selective polling: Not set
  383. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  384. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Sub-addressing: Not set
  385. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Password: Not set
  386. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Ready to transmit a data file (polling): Not set
  387. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Binary file transfer (BFT): Not set
  388. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Document transfer mode (DTM): Not set
  389. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Electronic data interchange (EDI): Not set
  390. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  391. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Basic transfer mode (BTM): Not set
  392. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Ready to transfer a character or mixed mode document (polling): Not set
  393. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= Character mode: Not set
  394. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Mixed mode (Annex E/T.4): Not set
  395. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  396. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Processable mode 26 (Rec. T.505): Not set
  397. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Digital network capability: Not set
  398. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Duplex capability: Half only
  399. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= JPEG coding: Not set
  400. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Full colour mode: Not set
  401. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= 12bits/pel component: Not set
  402. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  403. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= No subsampling (1:1:1): Not set
  404. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Custom illuminant: Not set
  405. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Custom gamut range: Not set
  406. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 1...= North American Letter (215.9mm x 279.4mm): Set
  407. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...1 ....= North American Legal (215.9mm x 355.6mm): Set
  408. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..1. ....= Single-progression sequential coding (Rec. T.85) basic: Set
  409. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Set
  410. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   0... ....= Extension indicator: Not set
  411. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  DIS with final frame tag
  412. 2017-02-28 19:49:37.017086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 80 00 ee fa c4 80 9d 80 80 80 78
  413. 2017-02-28 19:49:37.477085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  414. 2017-02-28 19:49:37.557099 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state R
  415. 2017-02-28 19:49:37.557099 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_TX to B_RX
  416. 2017-02-28 19:49:37.557099 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
  417. 2017-02-28 19:49:37.557099 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  418. 2017-02-28 19:49:37.557099 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4
  419. 2017-02-28 19:49:38.957084 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state R
  420. 2017-02-28 19:49:39.197087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state R
  421. 2017-02-28 19:49:39.197087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4-flagged
  422. 2017-02-28 19:49:40.697084 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T4-flagged (12000 remaining)
  423. 2017-02-28 19:49:40.697084 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  TSI without final frame tag
  424. 2017-02-28 19:49:40.697084 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 03 43 20 20 20 20 20 20 20 20 20 20 33 33 36 36 35 35 36 30 35 36
  425. 2017-02-28 19:49:40.697084 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Remote gave TSI as: "6506556633          "
  426. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop none (0 remaining)
  427. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  DCS with final frame tag
  428. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 83 00 e2 f0 80 80 80 80 80 80 08
  429. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state R
  430. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 DCS:
  431. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Store and forward Internet fax (T.37): Not set
  432. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Real-time Internet fax (T.38): Not set
  433. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= 3G mobile network: Not set
  434. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..1.= Receive fax: Set
  435. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..10 00..= Selected data signalling rate: V.17 14400bps
  436. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set
  437. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= 2-D coding: Set
  438. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..00= Recording width: 215mm +- 1%
  439. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 00..= Recording length: A4 (297mm)
  440. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .111 ....= Minimum scan line time: 0ms
  441. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  442. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Compressed/uncompressed mode: Compressed
  443. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Error correction mode (ECM): Non-ECM
  444. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= Frame size: 256 octets
  445. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= T.6 coding: Not set
  446. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  447. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= "Field not valid" supported: Not set
  448. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= T.43 coding: Not set
  449. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Plane interleave: Not set
  450. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set
  451. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Reserved for the use of extended voice coding set: Not set
  452. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  453. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= R8x15.4lines/mm: Not set
  454. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= 300x300pels/25.4mm: Not set
  455. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Not set
  456. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= Resolution type selection: Metric
  457. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  458. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Sub-addressing: Not set
  459. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Sender identification transmission: Not set
  460. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Binary file transfer (BFT): Not set
  461. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Document transfer mode (DTM): Not set
  462. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Electronic data interchange (EDI): Not set
  463. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  464. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Basic transfer mode (BTM): Not set
  465. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= Character mode: Not set
  466. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Mixed mode (Annex E/T.4): Not set
  467. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  468. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= Processable mode 26 (Rec. T.505): Not set
  469. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Digital network capability: Not set
  470. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Duplex capability: Half only
  471. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 0...= Full colour mode: Not set
  472. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= Full colour mode: Not set
  473. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Preferred Huffman tables: Not set
  474. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= 12bits/pel component: Not set
  475. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   1... ....= Extension indicator: Set
  476. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ...0= No subsampling (1:1:1): Not set
  477. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... ..0.= Custom illuminant: Not set
  478. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... .0..= Custom gamut range: Not set
  479. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .... 1...= North American Letter (215.9mm x 279.4mm): Set
  480. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ...0 ....= North American Legal (215.9mm x 355.6mm): Not set
  481. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set
  482. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set
  483. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30   0... ....= Extension indicator: Not set
  484. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Far end selected compression T.4 2-D (4)
  485. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:317 === Negotiation Result =======================================================
  486. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:318 Remote station id: 6506556633
  487. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:319 Local station id:  SpanDSP Fax Ident
  488. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:320 Transfer Rate:     14400
  489. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:322 ECM status         off
  490. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:323 remote country:
  491. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:324 remote vendor:
  492. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:325 remote model:
  493. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:327 ==============================================================================
  494. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Get document with modem (7) V.17 at 14400bps
  495. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state R to F_TCF
  496. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase C_NON_ECM_RX
  497. 2017-02-28 19:49:41.117115 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  498. 2017-02-28 19:49:41.197106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state F_TCF
  499. 2017-02-28 19:49:41.197106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_RX to C_NON_ECM_RX
  500. 2017-02-28 19:49:41.197106 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  501. 2017-02-28 19:49:41.197106 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 7
  502. 2017-02-28 19:49:41.197106 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  503. 2017-02-28 19:49:41.397103 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state F_TCF
  504. 2017-02-28 19:49:41.397103 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_TCF
  505. 2017-02-28 19:49:41.497118 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training in progress (-3) in state F_TCF
  506. 2017-02-28 19:49:42.417100 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Abort (-8) in state F_TCF
  507. 2017-02-28 19:49:42.797110 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training succeeded (-4) in state F_TCF
  508. 2017-02-28 19:49:42.797110 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2 (42560 remaining)
  509. 2017-02-28 19:49:44.417106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier down (-1) in state F_TCF
  510. 2017-02-28 19:49:44.417106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Trainability (TCF) test result - 23250 total bits. longest run of zeros was 21600
  511. 2017-02-28 19:49:44.417106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase C_NON_ECM_RX to B_TX
  512. 2017-02-28 19:49:44.417106 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  513. 2017-02-28 19:49:44.417106 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
  514. 2017-02-28 19:49:44.417106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_TCF to F_CFR
  515. 2017-02-28 19:49:44.417106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  CFR with final frame tag
  516. 2017-02-28 19:49:44.417106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 84
  517. 2017-02-28 19:49:45.497103 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state F_CFR
  518. 2017-02-28 19:49:45.577092 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase B_TX, state F_CFR
  519. 2017-02-28 19:49:45.577092 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_CFR to F_DOC_NON_ECM
  520. 2017-02-28 19:49:45.577092 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase B_TX to C_NON_ECM_RX
  521. 2017-02-28 19:49:45.577092 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  522. 2017-02-28 19:49:45.577092 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 7
  523. 2017-02-28 19:49:45.577092 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  524. 2017-02-28 19:49:45.577092 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  525. 2017-02-28 19:49:45.597127 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state F_DOC_NON_ECM
  526. 2017-02-28 19:49:47.117114 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state F_DOC_NON_ECM
  527. 2017-02-28 19:49:47.117114 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_DOC_NON_ECM
  528. 2017-02-28 19:49:47.257097 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training in progress (-3) in state F_DOC_NON_ECM
  529. 2017-02-28 19:49:47.277086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training succeeded (-4) in state F_DOC_NON_ECM
  530. 2017-02-28 19:49:47.277086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2 (42560 remaining)
  531. 2017-02-28 19:50:02.297084 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_DOC_NON_ECM to F_POST_DOC_NON_ECM
  532. 2017-02-28 19:50:02.297084 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_RX
  533. 2017-02-28 19:50:02.297084 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  534. 2017-02-28 19:50:02.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier down (-1) in state F_POST_DOC_NON_ECM
  535. 2017-02-28 19:50:02.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase C_NON_ECM_RX to D_RX
  536. 2017-02-28 19:50:02.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
  537. 2017-02-28 19:50:02.417093 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  538. 2017-02-28 19:50:02.517089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_POST_DOC_NON_ECM
  539. 2017-02-28 19:50:02.757100 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state F_POST_DOC_NON_ECM
  540. 2017-02-28 19:50:02.757100 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2-flagged
  541. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2-flagged (16640 remaining)
  542. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  MPS with final frame tag
  543. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 4f
  544. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state F_POST_DOC_NON_ECM
  545. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_TX
  546. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Page no = 1
  547. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image size = 1728 x 2156 pixels
  548. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image resolution = 8040/m x 7700/m
  549. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Compression = T.4 2-D (4)
  550. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Compressed image size = 27032 bytes
  551. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Bad rows = 0
  552. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Longest bad row run = 0
  553. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Page quality is perfect
  554. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:428 ==== Page Received ===========================================================
  555. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:429 Page no = 1
  556. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:430 Image type = bi-level (bi-level in the file)
  557. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:431 Image size = 1728 x 2156 pixels (1728 x 2156 pixels in the file)
  558. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:432 Image resolution = 8040/m x 7700/m (8040/m x 7700/m in the file)
  559. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:433 Compression = T.4 2-D (4)
  560. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:434 Compressed image size = 27032 bytes
  561. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:435 Bad rows = 0
  562. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:436 Longest bad row run = 0
  563. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:437 ==============================================================================
  564. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_POST_DOC_NON_ECM to III_Q
  565. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  MCF with final frame tag
  566. 2017-02-28 19:50:03.677113 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 8c
  567. 2017-02-28 19:50:03.757103 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state III_Q
  568. 2017-02-28 19:50:03.757103 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_RX to D_TX
  569. 2017-02-28 19:50:03.757103 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  570. 2017-02-28 19:50:03.757103 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
  571. 2017-02-28 19:50:04.817087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state III_Q
  572. 2017-02-28 19:50:04.897088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state III_Q
  573. 2017-02-28 19:50:04.897088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state III_Q to F_DOC_NON_ECM
  574. 2017-02-28 19:50:04.897088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_TX to C_NON_ECM_RX
  575. 2017-02-28 19:50:04.897088 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  576. 2017-02-28 19:50:04.897088 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 7
  577. 2017-02-28 19:50:04.897088 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  578. 2017-02-28 19:50:04.897088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  579. 2017-02-28 19:50:06.437091 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state F_DOC_NON_ECM
  580. 2017-02-28 19:50:06.437091 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_DOC_NON_ECM
  581. 2017-02-28 19:50:06.577096 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training in progress (-3) in state F_DOC_NON_ECM
  582. 2017-02-28 19:50:06.597093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training succeeded (-4) in state F_DOC_NON_ECM
  583. 2017-02-28 19:50:06.597093 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2 (42560 remaining)
  584. 2017-02-28 19:50:21.617085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_DOC_NON_ECM to F_POST_DOC_NON_ECM
  585. 2017-02-28 19:50:21.617085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_RX
  586. 2017-02-28 19:50:21.617085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  587. 2017-02-28 19:50:21.737086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier down (-1) in state F_POST_DOC_NON_ECM
  588. 2017-02-28 19:50:21.737086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase C_NON_ECM_RX to D_RX
  589. 2017-02-28 19:50:21.737086 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
  590. 2017-02-28 19:50:21.737086 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  591. 2017-02-28 19:50:21.837079 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_POST_DOC_NON_ECM
  592. 2017-02-28 19:50:22.077146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state F_POST_DOC_NON_ECM
  593. 2017-02-28 19:50:22.077146 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2-flagged
  594. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2-flagged (16480 remaining)
  595. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  MPS with final frame tag
  596. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 4f
  597. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state F_POST_DOC_NON_ECM
  598. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_TX
  599. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Page no = 2
  600. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image size = 1728 x 2155 pixels
  601. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image resolution = 8040/m x 7700/m
  602. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Compression = T.4 2-D (4)
  603. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Compressed image size = 26978 bytes
  604. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Bad rows = 1
  605. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Longest bad row run = 1
  606. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Page quality is good
  607. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:428 ==== Page Received ===========================================================
  608. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:429 Page no = 2
  609. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:430 Image type = bi-level (bi-level in the file)
  610. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:431 Image size = 1728 x 2155 pixels (1728 x 2155 pixels in the file)
  611. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:432 Image resolution = 8040/m x 7700/m (8040/m x 7700/m in the file)
  612. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:433 Compression = T.4 2-D (4)
  613. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:434 Compressed image size = 26978 bytes
  614. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:435 Bad rows = 1
  615. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:436 Longest bad row run = 1
  616. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:437 ==============================================================================
  617. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_POST_DOC_NON_ECM to III_Q
  618. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  MCF with final frame tag
  619. 2017-02-28 19:50:23.017107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 8c
  620. 2017-02-28 19:50:23.077174 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state III_Q
  621. 2017-02-28 19:50:23.077174 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_RX to D_TX
  622. 2017-02-28 19:50:23.077174 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  623. 2017-02-28 19:50:23.077174 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
  624. 2017-02-28 19:50:24.157107 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state III_Q
  625. 2017-02-28 19:50:24.237128 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state III_Q
  626. 2017-02-28 19:50:24.237128 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state III_Q to F_DOC_NON_ECM
  627. 2017-02-28 19:50:24.237128 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_TX to C_NON_ECM_RX
  628. 2017-02-28 19:50:24.237128 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  629. 2017-02-28 19:50:24.237128 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 7
  630. 2017-02-28 19:50:24.237128 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  631. 2017-02-28 19:50:24.237128 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  632. 2017-02-28 19:50:25.797106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state F_DOC_NON_ECM
  633. 2017-02-28 19:50:25.797106 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_DOC_NON_ECM
  634. 2017-02-28 19:50:25.937091 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training in progress (-3) in state F_DOC_NON_ECM
  635. 2017-02-28 19:50:25.957085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training succeeded (-4) in state F_DOC_NON_ECM
  636. 2017-02-28 19:50:25.957085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2 (42400 remaining)
  637. 2017-02-28 19:50:39.557094 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_DOC_NON_ECM to F_POST_DOC_NON_ECM
  638. 2017-02-28 19:50:39.557094 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_RX
  639. 2017-02-28 19:50:39.557094 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  640. 2017-02-28 19:50:39.677110 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier down (-1) in state F_POST_DOC_NON_ECM
  641. 2017-02-28 19:50:39.677110 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase C_NON_ECM_RX to D_RX
  642. 2017-02-28 19:50:39.677110 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
  643. 2017-02-28 19:50:39.677110 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  644. 2017-02-28 19:50:39.777125 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_POST_DOC_NON_ECM
  645. 2017-02-28 19:50:40.017094 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state F_POST_DOC_NON_ECM
  646. 2017-02-28 19:50:40.017094 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2-flagged
  647. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2-flagged (16480 remaining)
  648. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  MPS with final frame tag
  649. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 4f
  650. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state F_POST_DOC_NON_ECM
  651. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_TX
  652. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Page no = 3
  653. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image size = 1728 x 2156 pixels
  654. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image resolution = 8040/m x 7700/m
  655. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Compression = T.4 2-D (4)
  656. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Compressed image size = 24483 bytes
  657. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Bad rows = 0
  658. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Longest bad row run = 0
  659. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Page quality is perfect
  660. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:428 ==== Page Received ===========================================================
  661. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:429 Page no = 3
  662. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:430 Image type = bi-level (bi-level in the file)
  663. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:431 Image size = 1728 x 2156 pixels (1728 x 2156 pixels in the file)
  664. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:432 Image resolution = 8040/m x 7700/m (8040/m x 7700/m in the file)
  665. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:433 Compression = T.4 2-D (4)
  666. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:434 Compressed image size = 24483 bytes
  667. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:435 Bad rows = 0
  668. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:436 Longest bad row run = 0
  669. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:437 ==============================================================================
  670. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_POST_DOC_NON_ECM to III_Q
  671. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  MCF with final frame tag
  672. 2017-02-28 19:50:40.957087 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 8c
  673. 2017-02-28 19:50:41.037108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state III_Q
  674. 2017-02-28 19:50:41.037108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_RX to D_TX
  675. 2017-02-28 19:50:41.037108 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  676. 2017-02-28 19:50:41.037108 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
  677. 2017-02-28 19:50:42.117130 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state III_Q
  678. 2017-02-28 19:50:42.197086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state III_Q
  679. 2017-02-28 19:50:42.197086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state III_Q to F_DOC_NON_ECM
  680. 2017-02-28 19:50:42.197086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_TX to C_NON_ECM_RX
  681. 2017-02-28 19:50:42.197086 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  682. 2017-02-28 19:50:42.197086 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 7
  683. 2017-02-28 19:50:42.197086 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  684. 2017-02-28 19:50:42.197086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  685. 2017-02-28 19:50:43.757086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier up (-2) in state F_DOC_NON_ECM
  686. 2017-02-28 19:50:43.757086 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_DOC_NON_ECM
  687. 2017-02-28 19:50:43.897090 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training in progress (-3) in state F_DOC_NON_ECM
  688. 2017-02-28 19:50:43.917095 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Training succeeded (-4) in state F_DOC_NON_ECM
  689. 2017-02-28 19:50:43.917095 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2 (42400 remaining)
  690. 2017-02-28 19:50:55.017085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_DOC_NON_ECM to F_POST_DOC_NON_ECM
  691. 2017-02-28 19:50:55.017085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_RX
  692. 2017-02-28 19:50:55.017085 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2
  693. 2017-02-28 19:50:55.137110 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Non-ECM signal status is Carrier down (-1) in state F_POST_DOC_NON_ECM
  694. 2017-02-28 19:50:55.137110 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase C_NON_ECM_RX to D_RX
  695. 2017-02-28 19:50:55.137110 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
  696. 2017-02-28 19:50:55.137110 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  697. 2017-02-28 19:50:55.237090 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_POST_DOC_NON_ECM
  698. 2017-02-28 19:50:55.477099 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state F_POST_DOC_NON_ECM
  699. 2017-02-28 19:50:55.477099 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T2-flagged
  700. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T2-flagged (16640 remaining)
  701. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  EOP with final frame tag
  702. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 2f
  703. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state F_POST_DOC_NON_ECM
  704. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 End of procedure detected
  705. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Queuing phase D_TX
  706. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Page no = 4
  707. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image size = 1728 x 2156 pixels
  708. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Image resolution = 8040/m x 7700/m
  709. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Compression = T.4 2-D (4)
  710. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Compressed image size = 19971 bytes
  711. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Bad rows = 0
  712. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Longest bad row run = 0
  713. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Page quality is perfect
  714. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:428 ==== Page Received ===========================================================
  715. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:429 Page no = 4
  716. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:430 Image type = bi-level (bi-level in the file)
  717. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:431 Image size = 1728 x 2156 pixels (1728 x 2156 pixels in the file)
  718. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:432 Image resolution = 8040/m x 7700/m (8040/m x 7700/m in the file)
  719. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:433 Compression = T.4 2-D (4)
  720. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:434 Compressed image size = 19971 bytes
  721. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:435 Bad rows = 0
  722. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:436 Longest bad row run = 0
  723. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:437 ==============================================================================
  724. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state F_POST_DOC_NON_ECM to III_Q
  725. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  MCF with final frame tag
  726. 2017-02-28 19:50:56.397089 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Tx:  ff 13 8c
  727. 2017-02-28 19:50:56.477094 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state III_Q
  728. 2017-02-28 19:50:56.477094 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_RX to D_TX
  729. 2017-02-28 19:50:56.477094 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 0
  730. 2017-02-28 19:50:56.477094 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 4
  731. 2017-02-28 19:50:56.917116 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/‘hi'or‘x’='x'@138.197.209.147 [f4cc431e-c613-4cf3-af55-975643381f0f]
  732. 2017-02-28 19:50:56.917116 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) Running State Change CS_NEW (Cur 2 Tot 101)
  733. 2017-02-28 19:50:56.917116 [DEBUG] sofia.c:9815 sofia/internal/‘hi'or‘x’='x'@138.197.209.147 receiving invite from 62.210.245.31:41254 version: 1.6.14 git a8d53fd 2017-01-12 17:48:02Z 32bit
  734. 2017-02-28 19:50:56.917116 [DEBUG] sofia.c:9982 IP 62.210.245.31 Rejected by acl "nexmo". Falling back to Digest auth.
  735. 2017-02-28 19:50:56.917116 [DEBUG] sofia.c:2333 detaching session f4cc431e-c613-4cf3-af55-975643381f0f
  736. 2017-02-28 19:50:56.917116 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State NEW
  737. 2017-02-28 19:50:57.537088 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state III_Q
  738. 2017-02-28 19:50:57.617091 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state III_Q
  739. 2017-02-28 19:50:57.617091 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_TX to D_RX
  740. 2017-02-28 19:50:57.617091 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 4
  741. 2017-02-28 19:50:57.617091 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 0
  742. 2017-02-28 19:50:57.617091 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4
  743. 2017-02-28 19:50:59.037083 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier up (-2) in state III_Q
  744. 2017-02-28 19:50:59.277098 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Framing OK (-6) in state III_Q
  745. 2017-02-28 19:50:59.277098 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Start T4-flagged
  746. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Stop T4-flagged (16320 remaining)
  747. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  DCN with final frame tag
  748. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx:  ff 13 fb
  749. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Rx final frame in state III_Q
  750. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:496 ==============================================================================
  751. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:502 Fax successfully received.
  752. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:513 Remote station id: 6506556633
  753. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:514 Local station id:  SpanDSP Fax Ident
  754. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:515 Pages transferred: 4
  755. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:517 Total fax pages:   4
  756. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:518 Image resolution:  8040x7700
  757. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:519 Transfer Rate:     14400
  758. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:521 ECM status         off
  759. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:522 remote country:
  760. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:523 remote vendor:
  761. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:524 remote model:
  762. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:526 ==============================================================================
  763. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from state III_Q to CALL_FINISHED
  764. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_RX to CALL_FINISHED
  765. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set rx type 9
  766. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX FAX exchange complete
  767. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX Set tx type 9
  768. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW FAX FAX exchange complete
  769. 2017-02-28 19:51:00.237108 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Call completed
  770. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_codec.c:248 sofia/internal/+18024488966@sip.nexmo.com Restore previous codec PCMA:8.
  771. EXECUTE sofia/internal/+18024488966@sip.nexmo.com hangup()
  772. 2017-02-28 19:51:00.257108 [NOTICE] mod_dptools.c:1283 Hangup sofia/internal/+18024488966@sip.nexmo.com [CS_EXECUTE] [NORMAL_CLEARING]
  773. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_session.c:2797 sofia/internal/+18024488966@sip.nexmo.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  774. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/+18024488966@sip.nexmo.com) State EXECUTE going to sleep
  775. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+18024488966@sip.nexmo.com) Running State Change CS_HANGUP (Cur 2 Tot 101)
  776. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/+18024488966@sip.nexmo.com) Callstate Change ACTIVE -> HANGUP
  777. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/+18024488966@sip.nexmo.com) State HANGUP
  778. 2017-02-28 19:51:00.257108 [DEBUG] mod_sofia.c:438 Channel sofia/internal/+18024488966@sip.nexmo.com hanging up, cause: NORMAL_CLEARING
  779. 2017-02-28 19:51:00.257108 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/+18024488966@sip.nexmo.com
  780. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:60 sofia/internal/+18024488966@sip.nexmo.com Standard HANGUP, cause: NORMAL_CLEARING
  781. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/+18024488966@sip.nexmo.com) State HANGUP going to sleep
  782. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/+18024488966@sip.nexmo.com) State Change CS_HANGUP -> CS_REPORTING
  783. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/+18024488966@sip.nexmo.com) Running State Change CS_REPORTING (Cur 2 Tot 101)
  784. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/+18024488966@sip.nexmo.com) State REPORTING
  785. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:174 sofia/internal/+18024488966@sip.nexmo.com Standard REPORTING, cause: NORMAL_CLEARING
  786. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/+18024488966@sip.nexmo.com) State REPORTING going to sleep
  787. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/+18024488966@sip.nexmo.com) State Change CS_REPORTING -> CS_DESTROY
  788. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_session.c:1647 Session 100 (sofia/internal/+18024488966@sip.nexmo.com) Locked, Waiting on external entities
  789. 2017-02-28 19:51:00.257108 [NOTICE] switch_core_session.c:1665 Session 100 (sofia/internal/+18024488966@sip.nexmo.com) Ended
  790. 2017-02-28 19:51:00.257108 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/+18024488966@sip.nexmo.com [CS_DESTROY]
  791. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/+18024488966@sip.nexmo.com) Running State Change CS_DESTROY (Cur 1 Tot 101)
  792. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/+18024488966@sip.nexmo.com) State DESTROY
  793. 2017-02-28 19:51:00.257108 [DEBUG] mod_sofia.c:343 sofia/internal/+18024488966@sip.nexmo.com SOFIA DESTROY
  794. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:181 sofia/internal/+18024488966@sip.nexmo.com Standard DESTROY
  795. 2017-02-28 19:51:00.257108 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/+18024488966@sip.nexmo.com) State DESTROY going to sleep
  796. 2017-02-28 19:51:06.957127 [WARNING] switch_core_state_machine.c:687 f4cc431e-c613-4cf3-af55-975643381f0f sofia/internal/‘hi'or‘x’='x'@138.197.209.147 Abandoned
  797. 2017-02-28 19:51:06.957127 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/internal/‘hi'or‘x’='x'@138.197.209.147 [CS_NEW] [WRONG_CALL_STATE]
  798. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) Running State Change CS_HANGUP (Cur 1 Tot 101)
  799. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) Callstate Change DOWN -> HANGUP
  800. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State HANGUP
  801. 2017-02-28 19:51:06.957127 [DEBUG] mod_sofia.c:438 Channel sofia/internal/‘hi'or‘x’='x'@138.197.209.147 hanging up, cause: WRONG_CALL_STATE
  802. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:60 sofia/internal/‘hi'or‘x’='x'@138.197.209.147 Standard HANGUP, cause: WRONG_CALL_STATE
  803. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State HANGUP going to sleep
  804. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State Change CS_HANGUP -> CS_REPORTING
  805. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) Running State Change CS_REPORTING (Cur 1 Tot 101)
  806. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State REPORTING
  807. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:174 sofia/internal/‘hi'or‘x’='x'@138.197.209.147 Standard REPORTING, cause: WRONG_CALL_STATE
  808. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State REPORTING going to sleep
  809. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State Change CS_REPORTING -> CS_DESTROY
  810. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_session.c:1647 Session 101 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) Locked, Waiting on external entities
  811. 2017-02-28 19:51:06.957127 [NOTICE] switch_core_session.c:1665 Session 101 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) Ended
  812. 2017-02-28 19:51:06.957127 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/‘hi'or‘x’='x'@138.197.209.147 [CS_DESTROY]
  813. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) Running State Change CS_DESTROY (Cur 0 Tot 101)
  814. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State DESTROY
  815. 2017-02-28 19:51:06.957127 [DEBUG] mod_sofia.c:343 sofia/internal/‘hi'or‘x’='x'@138.197.209.147 SOFIA DESTROY
  816. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:181 sofia/internal/‘hi'or‘x’='x'@138.197.209.147 Standard DESTROY
  817. 2017-02-28 19:51:06.957127 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/‘hi'or‘x’='x'@138.197.209.147) State DESTROY going to sleep