Ive tested a few different call scenarios. I see a failed message after a
successful fax:

2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:345 Fax
processing not successful - result (26) Carrier lost during fax receive.

This happens at the end of every fax for one ITSP, BUT the sender was sent
as success confirmation. So the change at least lets the fax come in.


log snippet below:

2011-08-30 06:28:08.128571 [DEBUG] mod_sofia.c:1258 Remote
address:port [10.255.252.64:12904] has not changed.
2011-08-30 06:28:08.128571 [DEBUG] mod_sofia.c:1258 Remote
address:port [10.255.252.64:12904] has not changed.
2011-08-30 06:28:08.128571 [DEBUG] sofia_glue.c:182 sofia/
voice.myitdepartment.net/[email protected] image media sdp:
v=0
o=FreeSWITCH 1314688060 1314688065 IN IP4 10.255.252.64
s=FreeSWITCH
c=IN IP4 10.255.252.64
t=0 0
m=image 12024 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FaxFillBitRemoval
a=T38FaxRateManagement:transferredTCFlocalTCF
a=T38FaxMaxBuffer:2000
a=T38FaxMaxDatagram:400
a=T38FaxUdpEC:t38UDPFEC

2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:333
==============================================================================
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:345 Fax
processing not successful - result (26) Carrier lost during fax receive.
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:350 Remote
station id:
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:351 Local
station id:  SpanDSP Fax Ident
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:352 Pages
transferred: 1
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:354 Total fax
pages:   1
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:355 Image
resolution:  8031x7700
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:356 Transfer
Rate:     14400
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:358 ECM status
        on
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:359 remote
country:
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:360 remote
vendor:
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:361 remote
model:
2011-08-30 06:28:52.047010 [DEBUG] mod_spandsp_fax.c:363
==============================================================================
2011-08-30 06:28:52.047010 [DEBUG] switch_core_session.c:954 Send
signal sofia/voice.myitdepartment.net/[email protected] [BREAK]
2011-08-30 06:28:52.047010 [DEBUG] switch_core_codec.c:141 sofia/
voice.myitdepartment.net/[email protected] Restore previous codec
PCMU:0.
2011-08-30 06:28:52.047010 [ERR] switch_ivr.c:481 Invalid Command!
2011-08-30 06:28:52.142655 [DEBUG] switch_channel.c:2540 (sofia/
voice.myitdepartment.net/[email protected]) Callstate Change
ACTIVE -> HANGUP
2011-08-30 06:28:52.142655 [NOTICE] sofia.c:537 Hangup sofia/
voice.myitdepartment.net/[email protected] [CS_EXECUTE]
[NORMAL_CLEARING]
2011-08-30 06:28:52.142655 [DEBUG] switch_channel.c:2556 Send signal
sofia/voice.myitdepartment.net/[email protected] [KILL]
2011-08-30 06:28:52.142655 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/[email protected] [BREAK]
2011-08-30 06:28:52.142655 [DEBUG] switch_ivr_bridge.c:581 BRIDGE
THREAD DONE [sofia/voice.myitdepartment.net/[email protected]]
2011-08-30 06:28:52.142655 [DEBUG] switch_ivr_bridge.c:601 Send
signal sofia/voice.myitdepartment.net/sip:[email protected]:15060 [BREAK]
2011-08-30 06:28:52.144978 [DEBUG] switch_ivr_bridge.c:581 BRIDGE
THREAD DONE [sofia/voice.myitdepartment.net/sip:[email protected]:15060]
2011-08-30 06:28:52.144978 [DEBUG] switch_ivr_bridge.c:601 Send
signal sofia/voice.myitdepartment.net/[email protected] [BREAK]
2011-08-30 06:28:52.144978 [DEBUG] switch_channel.c:2540 (sofia/
voice.myitdepartment.net/sip:[email protected]:15060) Callstate Change
ACTIVE -> HANGUP
2011-08-30 06:28:52.144978 [NOTICE] switch_ivr_bridge.c:653 Hangup
sofia/voice.myitdepartment.net/sip:[email protected]:15060[CS_EXCHANGE_MEDIA]
[NORMAL_CLEARING]
2011-08-30 06:28:52.144978 [DEBUG] switch_channel.c:2556 Send signal
sofia/voice.myitdepartment.net/sip:[email protected]:15060 [KILL]
2011-08-30 06:28:52.144978 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/sip:[email protected]:15060 [BREAK]
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:369
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State
EXCHANGE_MEDIA going to sleep
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:320
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) Running State
Change CS_HANGUP
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:557
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State HANGUP
2011-08-30 06:28:52.144978 [DEBUG] mod_sofia.c:451 sofia/
voice.myitdepartment.net/sip:[email protected]:15060 Overriding SIP cause
480 with 200 from the other leg
2011-08-30 06:28:52.144978 [DEBUG] mod_sofia.c:457 Channel sofia/
voice.myitdepartment.net/sip:[email protected]:15060 hanging up, cause:
NORMAL_CLEARING
2011-08-30 06:28:52.144978 [DEBUG] mod_sofia.c:500 Sending BYE to
sofia/voice.myitdepartment.net/sip:[email protected]:15060
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:46
sofia/voice.myitdepartment.net/sip:[email protected]:15060 Standard HANGUP,
cause: NORMAL_CLEARING
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:557
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State HANGUP
going to sleep
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:351
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State Change
CS_HANGUP -> CS_REPORTING
2011-08-30 06:28:52.144978 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/sip:[email protected]:15060 [BREAK]
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:320
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) Running State
Change CS_REPORTING
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:617
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State REPORTING
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:53
sofia/voice.myitdepartment.net/sip:[email protected]:15060 Standard
REPORTING, cause: NORMAL_CLEARING
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:617
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State REPORTING
going to sleep
2011-08-30 06:28:52.144978 [DEBUG] switch_core_state_machine.c:345
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State Change
CS_REPORTING -> CS_DESTROY
2011-08-30 06:28:52.144978 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/sip:[email protected]:15060 [BREAK]
2011-08-30 06:28:52.144978 [DEBUG] switch_core_session.c:1288
Session 50 (sofia/voice.myitdepartment.net/sip:[email protected]:15060)
Locked, Waiting on external entities
2011-08-30 06:28:52.146939 [DEBUG] switch_channel.c:2540 (sofia/
voice.myitdepartment.net/[email protected]) Callstate Change ACTIVE
-> HANGUP
2011-08-30 06:28:52.146939 [NOTICE] sofia.c:537 Hangup sofia/
voice.myitdepartment.net/[email protected] [CS_EXECUTE]
[NORMAL_CLEARING]
2011-08-30 06:28:52.146939 [DEBUG] switch_channel.c:2556 Send signal
sofia/voice.myitdepartment.net/[email protected] [KILL]
2011-08-30 06:28:52.146939 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/[email protected] [BREAK]
2011-08-30 06:28:52.146939 [DEBUG] switch_ivr_bridge.c:1308 sofia/
voice.myitdepartment.net/[email protected] skip receive message
[UNBRIDGE] (channel is hungup already)
2011-08-30 06:28:52.146939 [DEBUG] switch_core_session.c:2060 sofia/
voice.myitdepartment.net/[email protected] skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:366
(sofia/voice.myitdepartment.net/[email protected]) State EXECUTE
going to sleep
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:320
(sofia/voice.myitdepartment.net/[email protected]) Running State
Change CS_HANGUP
2011-08-30 06:28:52.146939 [DEBUG] switch_core_session.c:2060 sofia/
voice.myitdepartment.net/[email protected] skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2011-08-30 06:28:52.146939 [NOTICE] switch_core_session.c:1306
Session 50 (sofia/voice.myitdepartment.net/sip:[email protected]:15060)
Ended
2011-08-30 06:28:52.146939 [NOTICE] switch_core_session.c:1308 Close
Channel sofia/voice.myitdepartment.net/sip:[email protected]:15060[CS_DESTROY]
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:449
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) Callstate
Change HANGUP -> DOWN
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:452
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) Running State
Change CS_DESTROY
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:462
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State DESTROY
2011-08-30 06:28:52.146939 [DEBUG] mod_sofia.c:362 sofia/
voice.myitdepartment.net/sip:[email protected]:15060 SOFIA DESTROY
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:60
sofia/voice.myitdepartment.net/sip:[email protected]:15060 Standard DESTROY
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:462
(sofia/voice.myitdepartment.net/sip:[email protected]:15060) State DESTROY
going to sleep
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:557
(sofia/voice.myitdepartment.net/[email protected]) State HANGUP
2011-08-30 06:28:52.146939 [DEBUG] mod_sofia.c:451 sofia/
voice.myitdepartment.net/[email protected] Overriding SIP cause 480
with 200 from the other leg
2011-08-30 06:28:52.146939 [DEBUG] mod_sofia.c:457 Channel sofia/
voice.myitdepartment.net/[email protected] hanging up, cause:
NORMAL_CLEARING
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:46
sofia/voice.myitdepartment.net/[email protected] Standard HANGUP,
cause: NORMAL_CLEARING
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:557
(sofia/voice.myitdepartment.net/[email protected]) State HANGUP going
to sleep
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:351
(sofia/voice.myitdepartment.net/[email protected]) State Change
CS_HANGUP -> CS_REPORTING
2011-08-30 06:28:52.146939 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/[email protected] [BREAK]
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:320
(sofia/voice.myitdepartment.net/[email protected]) Running State
Change CS_REPORTING
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:617
(sofia/voice.myitdepartment.net/[email protected]) State REPORTING
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:53
sofia/voice.myitdepartment.net/[email protected] Standard REPORTING,
cause: NORMAL_CLEARING
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:617
(sofia/voice.myitdepartment.net/[email protected]) State REPORTING
going to sleep
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:345
(sofia/voice.myitdepartment.net/[email protected]) State Change
CS_REPORTING -> CS_DESTROY
2011-08-30 06:28:52.146939 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/[email protected] [BREAK]
2011-08-30 06:28:52.146939 [DEBUG] switch_core_session.c:2060 sofia/
voice.myitdepartment.net/[email protected] skip receive message
[APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:366
(sofia/voice.myitdepartment.net/[email protected]) State EXECUTE
going to sleep
2011-08-30 06:28:52.146939 [DEBUG] switch_core_state_machine.c:320
(sofia/voice.myitdepartment.net/[email protected]) Running State
Change CS_HANGUP
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:557
(sofia/voice.myitdepartment.net/[email protected]) State HANGUP
2011-08-30 06:28:52.150208 [DEBUG] mod_sofia.c:451 sofia/
voice.myitdepartment.net/[email protected] Overriding SIP cause
480 with 200 from the other leg
2011-08-30 06:28:52.150208 [DEBUG] mod_sofia.c:457 Channel sofia/
voice.myitdepartment.net/[email protected] hanging up, cause:
NORMAL_CLEARING
2011-08-30 06:28:52.146939 [DEBUG] switch_core_session.c:1288
Session 51 (sofia/voice.myitdepartment.net/[email protected]) Locked,
Waiting on external entities
2011-08-30 06:28:52.150208 [NOTICE] switch_core_session.c:1306
Session 51 (sofia/voice.myitdepartment.net/[email protected]) Ended
2011-08-30 06:28:52.150208 [NOTICE] switch_core_session.c:1308 Close
Channel sofia/voice.myitdepartment.net/[email protected] [CS_DESTROY]
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:449
(sofia/voice.myitdepartment.net/[email protected]) Callstate Change
HANGUP -> DOWN
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:452
(sofia/voice.myitdepartment.net/[email protected]) Running State
Change CS_DESTROY
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:462
(sofia/voice.myitdepartment.net/[email protected]) State DESTROY
2011-08-30 06:28:52.150208 [DEBUG] mod_sofia.c:362 sofia/
voice.myitdepartment.net/[email protected] SOFIA DESTROY
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:60
sofia/voice.myitdepartment.net/[email protected] Standard DESTROY
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:462
(sofia/voice.myitdepartment.net/[email protected]) State DESTROY
going to sleep
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:46
sofia/voice.myitdepartment.net/[email protected] Standard HANGUP,
cause: NORMAL_CLEARING
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:557
(sofia/voice.myitdepartment.net/[email protected]) State HANGUP
going to sleep
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:351
(sofia/voice.myitdepartment.net/[email protected]) State Change
CS_HANGUP -> CS_REPORTING
2011-08-30 06:28:52.150208 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/[email protected] [BREAK]
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:320
(sofia/voice.myitdepartment.net/[email protected]) Running State
Change CS_REPORTING
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:617
(sofia/voice.myitdepartment.net/[email protected]) State
REPORTING
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:53
sofia/voice.myitdepartment.net/[email protected] Standard
REPORTING, cause: NORMAL_CLEARING
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:617
(sofia/voice.myitdepartment.net/[email protected]) State
REPORTING going to sleep
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:345
(sofia/voice.myitdepartment.net/[email protected]) State Change
CS_REPORTING -> CS_DESTROY
2011-08-30 06:28:52.150208 [DEBUG] switch_core_session.c:1116 Send
signal sofia/voice.myitdepartment.net/[email protected] [BREAK]
2011-08-30 06:28:52.150208 [DEBUG] switch_core_session.c:1288
Session 49 (sofia/voice.myitdepartment.net/[email protected])
Locked, Waiting on external entities
2011-08-30 06:28:52.150208 [NOTICE] switch_core_session.c:1306
Session 49 (sofia/voice.myitdepartment.net/[email protected])
Ended
2011-08-30 06:28:52.150208 [NOTICE] switch_core_session.c:1308 Close
Channel sofia/voice.myitdepartment.net/[email protected][CS_DESTROY]
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:449
(sofia/voice.myitdepartment.net/[email protected]) Callstate
Change HANGUP -> DOWN
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:452
(sofia/voice.myitdepartment.net/[email protected]) Running State
Change CS_DESTROY
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:462
(sofia/voice.myitdepartment.net/[email protected]) State DESTROY
2011-08-30 06:28:52.150208 [DEBUG] mod_sofia.c:362 sofia/
voice.myitdepartment.net/[email protected] SOFIA DESTROY
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:60
sofia/voice.myitdepartment.net/[email protected] Standard DESTROY
2011-08-30 06:28:52.150208 [DEBUG] switch_core_state_machine.c:462
(sofia/voice.myitdepartment.net/[email protected]) State DESTROY
going to sleep



*****

I also see some of these:

============================================================================
2011-08-30 06:32:31.967475 [DEBUG] mod_spandsp_fax.c:345 Fax processing not
successful - result (5) The HDLC carrier did not stop in a timely manner.

*****

Other ITSPs I have tested with work better. Some just dont work at all.

My intent is to make the error handling as much like a "fax machine" as
possible for the end user.


On Mon, Aug 29, 2011 at 11:35 AM, George Niculae <[email protected]> wrote:

> On Mon, Aug 29, 2011 at 2:25 PM, Tony Graziano
> <[email protected]> wrote:
> > OK, I will do that and supply it.
> >
>
> Thanks, I'm pretty sure that is  26  Carrier lost during fax receive -
> from the logs attached to JIRA:
>
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:333
>
> ==============================================================================
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:345 Fax
> processing not successful - result (26) Carrier lost during fax
> receive.
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:350
> Remote station id: FAX
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:351 Local
> station id:  SpanDSP Fax Ident
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:352 Pages
> transferred: 1
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:354 Total
> fax pages:   1
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:355 Image
> resolution:  8031x7700
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:356
> Transfer Rate:     14400
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:358 ECM
> status         on
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:359
> remote country:
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:360
> remote vendor:
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:361
> remote model:
>  [m [33m2011-07-08 17:42:51.493928 [DEBUG] mod_spandsp_fax.c:363
>
> ==============================================================================
>
> Though code 26 is not reflected in FS wiki page
> http://wiki.freeswitch.org/wiki/Variable_fax_result_code but it could
> be due to FS wiki not up to date. When you confirm this is the case
> I'll go back to FS code / FS user list and clarify this
>
> George
> _______________________________________________
> sipx-users mailing list
> [email protected]
> List Archive: http://list.sipfoundry.org/archive/sipx-users/
>



-- 
======================
Tony Graziano, Manager
Telephone: 434.984.8430
sip: [email protected]
Fax: 434.465.6833

Email: [email protected]

LAN/Telephony/Security and Control Systems Helpdesk:
Telephone: 434.984.8426
sip: [email protected]

Helpdesk Contract Customers:
http://support.myitdepartment.net

<http://support.myitdepartment.net>Blog:
http://blog.myitdepartment.net

Linked-In Profile: http://www.linkedin.com/pub/tony-graziano/14/4a6/7a4

Ask about our Internet faxservices!
_______________________________________________
sipx-users mailing list
[email protected]
List Archive: http://list.sipfoundry.org/archive/sipx-users/

Reply via email to