hi,brian log as below: ------------------------ start --------------------------- [ 2010-07-01 14:15:16.287030 [DEBUG] sofia.c:5928 IP 192.168.26.39 Approved by acl "192.168.26.0/24[]". Access Granted. [36m2010-07-01 14:15:16.289031 [NOTICE] switch_channel.c:776 New Channel sofia/internal/1000@192.168.26.39:15060[d8dc7307-efd6-48ed-8d85-d5f2d52deb10] [ 2010-07-01 14:15:16.289031 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@192.168.26.39:15060) Running State Change CS_NEW [ 2010-07-01 14:15:16.289031 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/1000@192.168.26.39:15060) State NEW [ 2010-07-01 14:15:16.331035 [DEBUG] sofia.c:4297 Channel sofia/internal/ 1000@192.168.26.39:15060 entering state [received][100] [ 2010-07-01 14:15:16.331035 [DEBUG] sofia.c:4308 Remote SDP: v=0 o=user1 3748 3748 IN IP4 192.168.26.39 s=- c=IN IP4 192.168.26.39 t=0 0 m=audio 6000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11,16 [ 2010-07-01 14:15:16.331035 [DEBUG] sofia_glue.c:3859 Audio Codec Compare [PCMA:8:8000:20]/[G7221:115:32000:20] [ 2010-07-01 14:15:16.331035 [DEBUG] sofia_glue.c:3859 Audio Codec Compare [PCMA:8:8000:20]/[G7221:107:16000:20] [ 2010-07-01 14:15:16.331035 [DEBUG] sofia_glue.c:3859 Audio Codec Compare [PCMA:8:8000:20]/[G722:9:8000:20] [ 2010-07-01 14:15:16.331035 [DEBUG] sofia_glue.c:3859 Audio Codec Compare [PCMA:8:8000:20]/[PCMU:0:8000:20] [ 2010-07-01 14:15:16.331035 [DEBUG] sofia_glue.c:3859 Audio Codec Compare [PCMA:8:8000:20]/[PCMA:8:8000:20] [ 2010-07-01 14:15:16.331035 [DEBUG] sofia_glue.c:2442 Set Codec sofia/internal/1000@192.168.26.39:15060 PCMA/8000 20 ms 160 samples [ 2010-07-01 14:15:16.331035 [DEBUG] sofia_glue.c:3798 Set 2833 dtmf send/recv payload to 101 [ 2010-07-01 14:15:16.331035 [DEBUG] sofia.c:4455 (sofia/internal/ 1000@192.168.26.39:15060) State Change CS_NEW -> CS_INIT [ 2010-07-01 14:15:16.331035 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000@192.168.26.39:15060 [BREAK] [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@192.168.26.39:15060) Running State Change CS_INIT [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/1000@192.168.26.39:15060) State INIT [ 2010-07-01 14:15:16.333036 [DEBUG] mod_sofia.c:83 sofia/internal/ 1000@192.168.26.39:15060 SOFIA INIT [ 2010-07-01 14:15:16.333036 [DEBUG] mod_sofia.c:119 (sofia/internal/ 1000@192.168.26.39:15060) State Change CS_INIT -> CS_ROUTING [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000@192.168.26.39:15060 [BREAK] [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/1000@192.168.26.39:15060) State INIT going to sleep [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@192.168.26.39:15060) Running State Change CS_ROUTING [ 2010-07-01 14:15:16.333036 [DEBUG] switch_channel.c:1471 (sofia/internal/ 1000@192.168.26.39:15060) Callstate Change DOWN -> RINGING [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/1000@192.168.26.39:15060) State ROUTING [ 2010-07-01 14:15:16.333036 [DEBUG] mod_sofia.c:142 sofia/internal/ 1000@192.168.26.39:15060 SOFIA ROUTING [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:77 sofia/internal/1000@192.168.26.39:15060 Standard ROUTING [32m2010-07-01 14:15:16.333036 [INFO] mod_dialplan_xml.c:331 Processing 1000->666666 in context public [ Dialplan: sofia/internal/1000@192.168.26.39:15060 parsing [public->fax] continue=false [ Dialplan: sofia/internal/1000@192.168.26.39:15060 Regex (FAIL) [fax] destination_number(666666) =~ /^fax$/ break=on-false [ Dialplan: sofia/internal/1000@192.168.26.39:15060 parsing [public->4444] continue=false [ Dialplan: sofia/internal/1000@192.168.26.39:15060 Regex (FAIL) [4444] destination_number(666666) =~ /^(4444)$/ break=on-false [ Dialplan: sofia/internal/1000@192.168.26.39:15060 parsing [public->fax] continue=false [ Dialplan: sofia/internal/1000@192.168.26.39:15060 Regex (FAIL) [fax] destination_number(666666) =~ /^fax$/ break=on-false [ Dialplan: sofia/internal/1000@192.168.26.39:15060 parsing [public->666666] continue=false [ Dialplan: sofia/internal/1000@192.168.26.39:15060 Regex (PASS) [666666] destination_number(666666) =~ /^(666666)$/ break=on-false [ Dialplan: sofia/internal/1000@192.168.26.39:15060 Action answer() [ Dialplan: sofia/internal/1000@192.168.26.39:15060 Action playback(silence_stream://2000) [ Dialplan: sofia/internal/1000@192.168.26.39:15060 Action rxfax(/tmp/999.tiff) [ Dialplan: sofia/internal/1000@192.168.26.39:15060 Action hangup() [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/1000@192.168.26.39:15060) State Change CS_ROUTING -> CS_EXECUTE [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000@192.168.26.39:15060 [BREAK] [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/1000@192.168.26.39:15060) State ROUTING going to sleep [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@192.168.26.39:15060) Running State Change CS_EXECUTE [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/1000@192.168.26.39:15060) State EXECUTE [ 2010-07-01 14:15:16.333036 [DEBUG] mod_sofia.c:235 sofia/internal/ 1000@192.168.26.39:15060 SOFIA EXECUTE [ 2010-07-01 14:15:16.333036 [DEBUG] switch_core_state_machine.c:157 sofia/internal/1000@192.168.26.39:15060 Standard EXECUTE [ EXECUTE sofia/internal/1000@192.168.26.39:15060 answer() [ 2010-07-01 14:15:16.367038 [DEBUG] sofia_glue.c:2682 AUDIO RTP [sofia/internal/1000@192.168.26.39:15060] 192.168.26.39 port 30734 -> 192.168.26.39 port 6000 codec: 8 ms: 20 [ 2010-07-01 14:15:16.369048 [DEBUG] switch_rtp.c:1413 Starting timer [soft] 160 bytes per 20ms [ 2010-07-01 14:15:16.371038 [DEBUG] sofia_glue.c:2892 Set 2833 dtmf send payload to 101 [ 2010-07-01 14:15:16.371038 [DEBUG] sofia_glue.c:2897 Set 2833 dtmf receive payload to 101 [ 2010-07-01 14:15:16.371038 [DEBUG] mod_sofia.c:669 Local SDP sofia/internal/1000@192.168.26.39:15060: v=0 o=FreeSWITCH 1277934182 1277934183 IN IP4 192.168.26.39 s=FreeSWITCH c=IN IP4 192.168.26.39 t=0 0 m=audio 30734 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv [ 2010-07-01 14:15:16.371038 [DEBUG] switch_core_session.c:647 Send signal sofia/internal/1000@192.168.26.39:15060 [BREAK] [ 2010-07-01 14:15:16.371038 [DEBUG] switch_channel.c:2494 (sofia/internal/ 1000@192.168.26.39:15060) Callstate Change RINGING -> ACTIVE [36m2010-07-01 14:15:16.371038 [NOTICE] mod_dptools.c:746 Channel [sofia/internal/1000@192.168.26.39:15060] has been answered [ 2010-07-01 14:15:16.371038 [DEBUG] sofia.c:4297 Channel sofia/internal/ 1000@192.168.26.39:15060 entering state [completed][200] [ 2010-07-01 14:15:16.371038 [DEBUG] sofia.c:4297 Channel sofia/internal/ 1000@192.168.26.39:15060 entering state [ready][200] [ EXECUTE sofia/internal/1000@192.168.26.39:15060playback(silence_stream://2000) [ 2010-07-01 14:15:16.371038 [DEBUG] switch_ivr_play_say.c:1161 Codec Activated L16@8000hz 1 channels 20ms [ 2010-07-01 14:15:18.364218 [DEBUG] switch_ivr_play_say.c:1468 done playing file [ EXECUTE sofia/internal/1000@192.168.26.39:15060 rxfax(/tmp/999.tiff) [ 2010-07-01 14:15:18.364218 [ERR] mod_spandsp.c:64 This is for fax test: receive fax [ 2010-07-01 14:15:18.364218 [ERR] mod_spandsp_fax.c:445 trans mode = 1 [ 2010-07-01 14:15:18.364218 [ERR] mod_spandsp_fax.c:591 This is for fax test: prag go to here!!! [ 2010-07-01 14:15:18.364218 [DEBUG] mod_spandsp_fax.c:1064 Raw read codec activation Success L16 20000 [ 2010-07-01 14:15:18.364218 [DEBUG] switch_core_codec.c:122 sofia/internal/1000@192.168.26.39:15060 Push codec L16:10 [ 2010-07-01 14:15:18.364218 [DEBUG] mod_spandsp_fax.c:1080 Raw write codec activation Success L16 [ 2010-07-01 14:15:18.645238 [ERR] mod_spandsp_fax.c:1119 pvt->t38_mode = 0 [ 2010-07-01 14:15:26.374918 [DEBUG] sofia.c:4297 Channel sofia/internal/ 1000@192.168.26.39:15060 entering state [received][100] [ 2010-07-01 14:15:26.374918 [DEBUG] sofia.c:4308 Remote SDP: v=0 o=root 0 0 IN IP4 192.168.26.39 s=Session SDP c=IN IP4 192.168.26.39 t=0 0 m=image 49172 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy [ 2010-07-01 14:15:26.382925 [ERR] mod_spandsp_fax.c:1119 pvt->t38_mode = 0 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:744 T38FaxVersion = 0 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:745 T38MaxBitRate = 9600 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:746 T38FaxFillBitRemoval = 1 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:747 T38FaxTranscodingMMR = 1 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:748 T38FaxTranscodingJBIG = 1 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:749 T38FaxRateManagement = 'transferredTCF' [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:750 T38FaxMaxBuffer = 200 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:751 T38FaxMaxDatagram = 72 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:752 T38FaxUdpEC = 't38UDPRedundancy' [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:753 T38VendorInfo = '' [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:754 ip = '192.168.26.39' [ 2010-07-01 14:15:26.382925 [DEBUG] mod_spandsp_fax.c:756 port = 49172 [ 2010-07-01 14:15:26.382925 [DEBUG] mod_sofia.c:1232 IMAGE UDPTL CHANGING DEST TO: [192.168.26.39:49172] [ 2010-07-01 14:15:26.382925 [DEBUG] sofia_glue.c:122 sofia/internal/ 1000@192.168.26.39:15060 image media sdp: v=0 o=FreeSWITCH 1277934182 1277934184 IN IP4 192.168.26.39 s=FreeSWITCH c=IN IP4 192.168.26.39 t=0 0 m=image 30734 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxFillBitRemoval a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:2000 a=T38FaxMaxDatagram:400 a=T38FaxUdpEC:t38UDPRedundancy a=T38VendorInfo:0 0 0 [ 2010-07-01 14:15:26.382925 [ERR] mod_spandsp_fax.c:445 trans mode = 0 [ 2010-07-01 14:15:26.382925 [DEBUG] sofia.c:4297 Channel sofia/internal/ 1000@192.168.26.39:15060 entering state [completed][200] [ 2010-07-01 14:15:46.390709 [ERR] mod_spandsp_fax.c:1119 pvt->t38_mode = 1 This is for fax test : s->state= 17 This is for fax test: command exceed max [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:302 result = 48 [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:304 ============================================================================== [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:316 Fax processing not successful - result (48) Disconnected after permitted retries. [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:321 Remote station id: [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:322 Local station id: SpanDSP Fax Ident [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:323 Pages transferred: 0 [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:325 Total fax pages: 0 [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:326 Image resolution: 0x0 [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:327 Transfer Rate: 14400 [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:329 ECM status off [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:330 remote country: [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:331 remote vendor: [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:332 remote model: [ 2010-07-01 14:15:49.052963 [DEBUG] mod_spandsp_fax.c:334 ============================================================================== [ 2010-07-01 14:15:51.388172 [DEBUG] switch_core_codec.c:146 sofia/internal/1000@192.168.26.39:15060 Restore previous codec PCMA:8. [ EXECUTE sofia/internal/1000@192.168.26.39:15060 hangup() [ 2010-07-01 14:15:51.388172 [DEBUG] switch_channel.c:2261 (sofia/internal/ 1000@192.168.26.39:15060) Callstate Change ACTIVE -> HANGUP [36m2010-07-01 14:15:51.388172 [NOTICE] mod_dptools.c:732 Hangup sofia/internal/1000@192.168.26.39:15060 [CS_EXECUTE] [NORMAL_CLEARING] [ 2010-07-01 14:15:51.388172 [DEBUG] switch_channel.c:2277 Send signal sofia/internal/1000@192.168.26.39:15060 [KILL] [ 2010-07-01 14:15:51.388172 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000@192.168.26.39:15060 [BREAK] [ 2010-07-01 14:15:51.388172 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/1000@192.168.26.39:15060) State EXECUTE going to sleep [ 2010-07-01 14:15:51.391171 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@192.168.26.39:15060) Running State Change CS_HANGUP [ 2010-07-01 14:15:51.391171 [DEBUG] switch_core_state_machine.c:500 (sofia/internal/1000@192.168.26.39:15060) State HANGUP [ 2010-07-01 14:15:51.391171 [DEBUG] mod_sofia.c:447 Channel sofia/internal/1000@192.168.26.39:15060 hanging up, cause: NORMAL_CLEARING [ 2010-07-01 14:15:51.433177 [DEBUG] mod_sofia.c:490 Sending BYE to sofia/internal/1000@192.168.26.39:15060 [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:46 sofia/internal/1000@192.168.26.39:15060 Standard HANGUP, cause: NORMAL_CLEARING [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:500 (sofia/internal/1000@192.168.26.39:15060) State HANGUP going to sleep [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/1000@192.168.26.39:15060) State Change CS_HANGUP -> CS_REPORTING [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000@192.168.26.39:15060 [BREAK] [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@192.168.26.39:15060) Running State Change CS_REPORTING [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:591 (sofia/internal/1000@192.168.26.39:15060) State REPORTING [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:53 sofia/internal/1000@192.168.26.39:15060 Standard REPORTING, cause: NORMAL_CLEARING [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:591 (sofia/internal/1000@192.168.26.39:15060) State REPORTING going to sleep [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/1000@192.168.26.39:15060) State Change CS_REPORTING -> CS_DESTROY [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_session.c:1027 Send signal sofia/internal/1000@192.168.26.39:15060 [BREAK] [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_session.c:1175 Session 1 (sofia/internal/1000@192.168.26.39:15060) Locked, Waiting on external entities [36m2010-07-01 14:15:51.433177 [NOTICE] switch_core_session.c:1193 Session 1 (sofia/internal/1000@192.168.26.39:15060) Ended [36m2010-07-01 14:15:51.433177 [NOTICE] switch_core_session.c:1195 Close Channel sofia/internal/1000@192.168.26.39:15060 [CS_DESTROY] [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:427 (sofia/internal/1000@192.168.26.39:15060) Callstate Change HANGUP -> DOWN [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:430 (sofia/internal/1000@192.168.26.39:15060) Running State Change CS_DESTROY [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/1000@192.168.26.39:15060) State DESTROY [ 2010-07-01 14:15:51.433177 [DEBUG] mod_sofia.c:352 sofia/internal/ 1000@192.168.26.39:15060 SOFIA DESTROY [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.26.39:15060 Standard DESTROY [ 2010-07-01 14:15:51.433177 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/1000@192.168.26.39:15060) State DESTROY going to sleep ------------------------ end ------------------------- regards sammy 2010/7/1 Brian West <brian@freeswitch.org>
You'll need to provide the sip trace and full debug logs.
/b
On Jul 1, 2010, at 3:30 AM, chi zhang wrote:
Does anyone know the reason? Where is the span_log of spandsp lib ? i cannt find it...
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org