Anthony,

Thanks for replying so fast.

It should be enough log I think - you can see that the dialplan first goes to execute:

Dialplan: sofia/internal/anonymous@anonymous.invalid Action
 bridge(modem/13/a)

*but* for some reasons it ends up being answered by /dev/FS/FS10 (I just patched one line in the source to make it create the links in a subdir so the permissions could be fixed for running as non-root user).

2012-12-11 14:43:18.873181 [DEBUG] mod_spandsp_modem.c:1417 Modem
 /dev/FS/FS10 [ONHOOK] - Changing state to ACQUIRED

And then for some bizarre reason FS continues as if we'd bridged to modem/10/whatever:

2012-12-11 14:43:18.873181 [DEBUG] mod_spandsp_modem.c:769 modem/10/a
 setup codec L16/8000/20

These are all definitely executed from the same extension in the dialplan. I've seen about 7 instances out of about 120 inbound faxes over the last few days. I've reverted to t38_gatewaying into t38modem endpoints for now as it seems to obey normal DP rules.

PS.
 
Perhaps related to this issue (think the code is in mod_spandsp) is that I've also found that the version of FS I compiled from GIT stable (? - not head at least - a bit confused about the new structure) a couple of days ago won't let me use t38_passthru with t38modem any more - even though it works reasonably well with and SPA3102. I am using the same binaries of t38modem I used with an older release which worked perfectly, same debian server, same kernel. The only thing I can tell you about the previous version that worked is that I built .debs from git on April 9 this year - I don't have the git downloaded tree any more to give you the revision (unless you can tell me another way of finding it without having the source tree). Luckily using proxy_media provides a fallback here, but I'd prefer to use the preferred method.

Also I've tried to use the FS modems for outbound faxing but I have a lot of problems on sessions with ECM where the destination sees increasingly more missing frames and tries to retrain the sender to a lower speed, and the lost frames get worse and worse. Researching on Hylafax mailing lists seems to suggest this means the sending modem does not do flow control properly and so the sending Hylafax does not know to stop pushing data at the modem. Consequently as the receiver asks to drop the speed the problem gets worse - by the time we get to 4800bps not even a single frame makes it through! The only inbound problem is what I describe above.

Without ECM an outbound fax completes but on the RX side there are large chunks of the page missing even though Hylafax on the sending side reports send OK. I guess that's why you should never disable ECM as Brian said.

Happy to open Jira for these last two but there is hardly anything in the FS log that looked different, just ended up with 100% hangups in the first place and sporadic faxing out in the second case.

Best regards

Alex


On 11/12/12 18:37, Anthony Minessale wrote:
hard to tell its not a complete log, is $1 not the same as what you captured with the parens?



On Tue, Dec 11, 2012 at 11:19 AM, Alex Crow <acrow@integrafin.co.uk> wrote:
Hi,

Please see the below log snippet. I am accepting faxes from an ISDN
gateway on sequential numbers and attempting to route them into distinct
freeswitch modems by taking the last two digits of the called number thusly:

    <condition field="destination_number"
expression="^12([1-2][0-9]|3[0-6])$">
         <!--<action application="set" data="ignore_early_media=true"/>-->
         <action application="set" data="sip_ignore_reinvites=true"/>
         <action application="set"
data="absolute_codec_string='PCMA,PCMU'"/>
         <action application="set" data="jitterbuffer_msec=600:600:60"/>
         <action application="set" data="sip_jitter_buffer_plc=false"/>
         <action application="bridge" data="modem/$1/a"/>
    </condition>

And then have Hylafax email them on depending on which modem they
arrived on (via FaxDispatch).

However as you can see from the below log snippets, it seems that FS is
quite happy to change the modem device from what is actually delivered
via the dialplan. Consequently a number of my faxes are now being routed
to the wrong people.

Is my bridge dest wrong? Should it be something like modem/$1/0 instead
of "a"?

Thanks

Alex

Dialplan: sofia/internal/anonymous@anonymous.invalid Action
set(sip_ignore_reinvites=true)
Dialplan: sofia/internal/anonymous@anonymous.invalid Action
set(absolute_codec_string='PCMA,PCMU')
Dialplan: sofia/internal/anonymous@anonymous.invalid Action
set(jitterbuffer_msec=600:600:60)
Dialplan: sofia/internal/anonymous@anonymous.invalid Action
set(sip_jitter_buffer_plc=false)
Dialplan: sofia/internal/anonymous@anonymous.invalid Action
bridge(modem/13/a)
2012-12-11 14:43:18.873181 [DEBUG] switch_core_state_machine.c:167
(sofia/internal/anonymous@anonymous.invalid) State Change CS_ROUTING ->
CS_EXECUTE
2012-12-11 14:43:18.873181 [DEBUG] switch_core_session.c:1283 Send
signal sofia/internal/anonymous@anonymous.invalid [BREAK]
2012-12-11 14:43:18.873181 [DEBUG] switch_core_state_machine.c:470
(sofia/internal/anonymous@anonymous.invalid) State ROUTING going to sleep
2012-12-11 14:43:18.873181 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/anonymous@anonymous.invalid) Running State Change CS_EXECUTE
2012-12-11 14:43:18.873181 [DEBUG] switch_core_state_machine.c:477
(sofia/internal/anonymous@anonymous.invalid) State EXECUTE
2012-12-11 14:43:18.873181 [DEBUG] mod_sofia.c:242
sofia/internal/anonymous@anonymous.invalid SOFIA EXECUTE
2012-12-11 14:43:18.873181 [DEBUG] switch_core_state_machine.c:209
sofia/internal/anonymous@anonymous.invalid Standard EXECUTE
EXECUTE sofia/internal/anonymous@anonymous.invalid set(call_direction=local)
2012-12-11 14:43:18.873181 [DEBUG] mod_dptools.c:1344
sofia/internal/anonymous@anonymous.invalid SET [call_direction]=[local]
EXECUTE sofia/internal/anonymous@anonymous.invalid set(open=true)
2012-12-11 14:43:18.873181 [DEBUG] mod_dptools.c:1344
sofia/internal/anonymous@anonymous.invalid SET [open]=[true]
EXECUTE sofia/internal/anonymous@anonymous.invalid
hash(insert/192.168.20.245-spymap/anonymous/4e5c4699-aa22-4998-b7fa-b50a52c940fb)
EXECUTE sofia/internal/anonymous@anonymous.invalid
hash(insert/192.168.20.245-last_dial/anonymous/1213)
EXECUTE sofia/internal/anonymous@anonymous.invalid
hash(insert/192.168.20.245-last_dial/global/4e5c4699-aa22-4998-b7fa-b50a52c940fb)
EXECUTE sofia/internal/anonymous@anonymous.invalid set(RFC2822_DATE=Tue,
11 Dec 2012 14:43:18 +0000)
2012-12-11 14:43:18.873181 [DEBUG] mod_dptools.c:1344
sofia/internal/anonymous@anonymous.invalid SET [RFC2822_DATE]=[Tue, 11
Dec 2012 14:43:18 +0000]
EXECUTE sofia/internal/anonymous@anonymous.invalid
set(sip_ignore_reinvites=true)
2012-12-11 14:43:18.873181 [DEBUG] mod_dptools.c:1344
sofia/internal/anonymous@anonymous.invalid SET [sip_ignore_reinvites]=[true]
EXECUTE sofia/internal/anonymous@anonymous.invalid
set(absolute_codec_string='PCMA,PCMU')
2012-12-11 14:43:18.873181 [DEBUG] mod_dptools.c:1344
sofia/internal/anonymous@anonymous.invalid SET
[absolute_codec_string]=['PCMA,PCMU']
EXECUTE sofia/internal/anonymous@anonymous.invalid
set(jitterbuffer_msec=600:600:60)
2012-12-11 14:43:18.873181 [DEBUG] mod_dptools.c:1344
sofia/internal/anonymous@anonymous.invalid SET
[jitterbuffer_msec]=[600:600:60]
EXECUTE sofia/internal/anonymous@anonymous.invalid
set(sip_jitter_buffer_plc=false)
2012-12-11 14:43:18.873181 [DEBUG] mod_dptools.c:1344
sofia/internal/anonymous@anonymous.invalid SET
[sip_jitter_buffer_plc]=[false]
EXECUTE sofia/internal/anonymous@anonymous.invalid bridge(modem/13/a)
2012-12-11 14:43:18.873181 [DEBUG] switch_channel.c:1089
sofia/internal/anonymous@anonymous.invalid EXPORTING[export_vars]
[domain_name]=[192.168.20.245] to event
2012-12-11 14:43:18.873181 [DEBUG] switch_ivr_originate.c:2022 Parsing
global variables
2012-12-11 14:43:18.873181 [DEBUG] mod_spandsp_modem.c:1417 Modem
/dev/FS/FS10 [ONHOOK] - Changing state to ACQUIRED
2012-12-11 14:43:18.873181 [NOTICE] switch_channel.c:968 New Channel
modem/10/a [a202aef1-1628-45e8-b720-9f5368aa4565]
2012-12-11 14:43:18.873181 [DEBUG] mod_spandsp_modem.c:769 modem/10/a
setup codec L16/8000/20
2012-12-11 14:43:18.873181 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [rtp_autoflush_during_bridge]=[false]
2012-12-11 14:43:18.873181 [DEBUG] mod_spandsp_modem.c:896 (modem/10/a)
State Change CS_NEW -> CS_INIT
2012-12-11 14:43:18.873181 [DEBUG] switch_core_session.c:1283 Send
signal modem/10/a [BREAK]
2012-12-11 14:43:18.873181 [DEBUG] mod_spandsp_modem.c:581 modem/10/a
CHANNEL KILL
2012-12-11 14:43:18.893118 [DEBUG] switch_core_state_machine.c:415
(modem/10/a) Running State Change CS_INIT
2012-12-11 14:43:18.893118 [DEBUG] switch_core_state_machine.c:454
(modem/10/a) State INIT
2012-12-11 14:43:18.893118 [DEBUG] mod_spandsp_modem.c:461 Modem
/dev/FS/FS10 [ACQUIRED] - Changing state to RINGING
2012-12-11 14:43:18.893118 [DEBUG] mod_spandsp_modem.c:1131 Modem
/dev/FS/FS10 [RINGING] - RNG 1


And another one:


EXECUTE sofia/internal/anonymous@anonymous.invalid bridge(modem/23/a)
2012-12-11 13:42:20.813107 [DEBUG] switch_channel.c:1089
sofia/internal/anonymous@anonymous.invalid EXPORTING[export_vars]
[domain_name]=[192.168.20.245] to event
2012-12-11 13:42:20.813107 [DEBUG] switch_ivr_originate.c:2022 Parsing
global variables
2012-12-11 13:42:20.813107 [DEBUG] mod_spandsp_modem.c:1417 Modem
/dev/FS/FS26 [ONHOOK] - Changing state to ACQUIRED
2012-12-11 13:42:20.813107 [NOTICE] switch_channel.c:968 New Channel
modem/26/a [32872ae9-6f78-45b0-af56-4b18c9de7160]
2012-12-11 13:42:20.813107 [DEBUG] mod_spandsp_modem.c:769 modem/26/a
setup codec L16/8000/20
2012-12-11 13:42:20.813107 [DEBUG] switch_channel.c:1135 EXPORT
(export_vars) [rtp_autoflush_during_bridge]=[false]
2012-12-11 13:42:20.813107 [DEBUG] mod_spandsp_modem.c:896 (modem/26/a)
State Change CS_NEW -> CS_INIT
2012-12-11 13:42:20.813107 [DEBUG] switch_core_session.c:1283 Send
signal modem/26/a [BREAK]
2012-12-11 13:42:20.813107 [DEBUG] mod_spandsp_modem.c:581 modem/26/a
CHANNEL KILL
2012-12-11 13:42:20.813107 [DEBUG] switch_core_state_machine.c:415
(modem/26/a) Running State Change CS_INIT
2012-12-11 13:42:20.813107 [DEBUG] switch_core_state_machine.c:454
(modem/26/a) State INIT
2012-12-11 13:42:20.813107 [DEBUG] mod_spandsp_modem.c:461 Modem
/dev/FS/FS26 [ACQUIRED] - Changing state to RINGING
2012-12-11 13:42:20.813107 [DEBUG] mod_spandsp_modem.c:1131 Modem
/dev/FS/FS26 [RINGING] - RNG 1
2012-12-11 13:42:20.833137 [DEBUG] mod_spandsp_modem.c:1038 Modem
/dev/FS/FS26 [RINGING] - Answering
2012-12-11 13:42:20.833137 [DEBUG] mod_spandsp_modem.c:1040 Modem
/dev/FS/FS26 [RINGING] - Changing state to ANSWERED

_________________________________________________________________________
Professional FreeSWITCH Consulting Services:
consulting@freeswitch.org
http://www.freeswitchsolutions.com

FreeSWITCH-powered IP PBX: The CudaTel Communication Server
http://www.cudatel.com

Official FreeSWITCH Sites
http://www.freeswitch.org
http://wiki.freeswitch.org
http://www.cluecon.com

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



--
Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/
ClueCon http://www.cluecon.com/
Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm
MSN:anthony_minessale@hotmail.com
GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com
IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference
sip:888@conference.freeswitch.org
googletalk:conf+888@conference.freeswitch.org
pstn:+19193869900

--
This message has been scanned for viruses and
dangerous content by MailScanner, and is
believed to be clean. 

_________________________________________________________________________
Professional FreeSWITCH Consulting Services:
consulting@freeswitch.org
http://www.freeswitchsolutions.com

FreeSWITCH-powered IP PBX: The CudaTel Communication Server
http://www.cudatel.com

Official FreeSWITCH Sites
http://www.freeswitch.org
http://wiki.freeswitch.org
http://www.cluecon.com

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