Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Fax is not hanging up after successful completion #31

Open
robooeko opened this issue Apr 23, 2017 · 43 comments
Open

Fax is not hanging up after successful completion #31

robooeko opened this issue Apr 23, 2017 · 43 comments
Labels
bug freeswitch

Comments

@robooeko
Copy link

Hi Team,
i have installed gofaxip and freeswitch as per your instructions and started testing it. After some tries and adjustments in the config i could create successfully my first faxes with Hylafax and freeswitch, gofaxip however in almost all the cases the fax keeps the voip connection open forever even if spandsp reports through the event socket that the fax was successfully delivered. I have to shutdown freeswitch to get the fax to hang up and complete. This happens in almost all my test cases. See one log attached:

2017/04/22 23:23:07.052553 Processing HylaFAX Job 440 as e1062558-b04b-4fc9-8a58-5336b6511b2b
2017/04/22 23:23:07.089390 Originating channel to (FAX NUMBER) using gateway default
2017/04/22 23:23:13.932231 Originate successful
2017/04/22 23:23:13.932649 Call state change: EARLY
2017/04/22 23:23:13.933085 Call state change: ACTIVE
2017/04/22 23:23:21.784950 Remote ID: "", Transfer Rate: 14400, ECM=true
2017/04/22 23:23:34.373968 Page 1 sent: Image Size: 1728x1162, Compression: T.6, Comp Size: 1701 bytes, Bad Rows: 0
2017/04/22 23:23:54.439536 Page 2 sent: Image Size: 1728x1162, Compression: T.6, Comp Size: 26519 bytes, Bad Rows: 0

Hangs up only because i shutdown freeswitch manually after waiting another 6 mins to see if fax will hang up automatically.
2017/04/22 23:29:27.862314 Call state change: HANGUP
2017/04/22 23:29:27.865432 Success: true, Hangup Cause: SYSTEM_SHUTDOWN, Result: OK

Regards
Rob
@robooeko robooeko changed the title Fax is not haning up after successful completion Fax is not hanging up after successful completion Apr 23, 2017
@robooeko
Copy link
Author

As an additional info. This happens only when T38 support is switched on my router/sip gateway. If T38 is switched off the fax hangs up correctly after a successfully sent fax. If T38 support is switched on i can see that leg A (internal connection from endpoint behind router to router/sip gateway) is transmitted with T38 but on leg B (external connection to fax somewhere in the world) the connection is running without T38. In that scenario the fax is also sent successfully but the connection remains open forever and fax/freeswitch is not hanging up.

@mwreimer
Copy link

mwreimer commented May 30, 2017 •
edited
Loading

Hello. Great project!
Same issue running on Ubuntu 16.04. Freeswitch.log shows:

mod_spandsp_fax.c:276 FLOW T.30 Success - delivered 1 pages
mod_spandsp_fax.c:276 FLOW T.30 Receive complete in phase D_RX, state C
mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state C
mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_RX to D_TX
mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
mod_spandsp_fax.c:276 FLOW T.38T Set tx type 4
mod_spandsp_fax.c:276 FLOW T.30 No signal is present
mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state C
mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase D_TX, state C
mod_spandsp_fax.c:276 FLOW T.30 Starting final pause before disconnecting
mod_spandsp_fax.c:276 FLOW T.30 Changing from phase D_TX to E
mod_spandsp_fax.c:276 FLOW T.38T Set rx type 0
mod_spandsp_fax.c:276 FLOW T.38T Set tx type 1
mod_spandsp_fax.c:276 FLOW T.30 Changing from state C to B
mod_spandsp_fax.c:276 FLOW T.30 Send complete in phase E, state B
mod_spandsp_fax.c:496 ==============================================================================
mod_spandsp_fax.c:500 Fax successfully sent.
mod_spandsp_fax.c:513 Remote station id: VoxFax
mod_spandsp_fax.c:514 Local station id: +1 613 123 4567
mod_spandsp_fax.c:515 Pages transferred: 1
mod_spandsp_fax.c:517 Total fax pages: 1
mod_spandsp_fax.c:518 Image resolution: 8040x3850
mod_spandsp_fax.c:519 Transfer Rate: 9600
mod_spandsp_fax.c:521 ECM status off
mod_spandsp_fax.c:522 remote country:
mod_spandsp_fax.c:523 remote vendor:
mod_spandsp_fax.c:524 remote model:
mod_spandsp_fax.c:526 ==============================================================================
mod_spandsp_fax.c:276 FLOW T.30 Changing from state B to CALL_FINISHED
mod_spandsp_fax.c:276 FLOW T.30 Changing from phase E to CALL_FINISHED
mod_spandsp_fax.c:276 FLOW T.38T Set rx type 9
mod_spandsp_fax.c:276 FLOW T.38T Set tx type 9
mod_spandsp_fax.c:276 FLOW T.38T FAX exchange complete
mod_spandsp_fax.c:276 FLOW T.30 Call completed

Yet, faxstat -s shows:

HylaFAX scheduler on mwr: Running
Modem freeswitch0 (): Sending facsimile

JID Pri S Owner Number Pages Dials TTS Status
9 127 R root 16131234567 1:1 2:12 Sending 9600

Here, restarting Hylafax resends the fax as it thinks it was interrupted.

A work-around is to disable T.38 in /etc/gofax.conf and to restart the stack.
; Disable T.38
disablet38 = true

I tried this on another server with another ISP and used a non-standard port (5080 instead of 5060) for SIP communication and it worked sporadically. I think it is a bug in freeswitch or in gofaxip. Unfortunately my skills are not enough to try to provide a patch.

Thanks again for an excellent software product, running well with T.30.

@denzs
Copy link
Member

denzs commented Aug 17, 2017

I encountered similar problems with the latest Freeswitch Stable (1.6.19) in combination with a Patton Smartnode...

After transferring the fax, the Smartnode tries to re-invite to g.711 again.
With Freeswitch 1.6.15 that was answered with "488 not acceptable here" and the dialog was shutdown properly...

With Freeswitch 1.6.19, the re-invite to g.711 is answered with 200 OK, and then the dialog hangs...

I downgraded to 1.6.15 and deactivated the fax detection after 1 second on the patton (could have been sufficent alone!), that worked for me.

We will have a look on that and ensure, gofax.ip will work properly with the current version of Freeswitch.

@denzs
Copy link
Member

denzs commented Aug 17, 2017

I think the reason for this are:
https://freeswitch.org/jira/browse/FS-6544 and/or
https://freeswitch.org/jira/browse/FS-10059

@sjaeckel
Copy link
Contributor

Is there already a solution resp. the real reason known?

I've a setup where I can reproduce this behavior by sending a fax (via our sip provider) to myself.

$ /usr/bin/freeswitch -version                                                                 
FreeSWITCH version: 1.6.19-36-7a77e0b~64bit (-36-7a77e0b 64bit)
$ /usr/bin/gofaxd --version
1.1

If you need detailed logs or other information feel free to ask for it.

@chaim1989
Copy link

Did anyone found a solution for that, it happens to me once a day, it's usually on jobs with more than 10 pages....

@rbetancor
Copy link

rbetancor commented Nov 2, 2017 via email

@chaim1989
Copy link

can you give me the details of your enviroment,
i will be happy to find an enviroments where its working perfect,
os, hardware/virtualization, etc.

@rbetancor
Copy link

rbetancor commented Nov 3, 2017 via email

@sjaeckel
Copy link
Contributor

sjaeckel commented Nov 8, 2017

@chaim1989 you can try to build and run the version of PR #37. probably that solves the issue for you (and if it makes it worse feel free to report that in the PR)

@chaim1989
Copy link

this is the input of my faxstat -s command:

2340 127 R fax 97248600303 14:14 1:4 Sending 14400
2345 127 R fax 97236178866 8:8 1:4 Sending 14400
2344 127 R fax 97226463474 10:10 1:4 Sending 14400/ECM
2347 127 B fax 97236178866 0:0 0:4 Blocked by concurrent cal

it's just get stuck like that at least twice a day, usually on jobs that are more then 5 pages long, it only releases when i do "systemctl restart freeswitch"

any ideas ? does it related to this issue of fax not hangingup
and BTW i did change to the PR version of sjaeckel (i just replaced the binary of gofaxd)

@sjaeckel
Copy link
Contributor

i did change to the PR version of sjaeckel (i just replaced the binary of gofaxd)

okay, then you're having a different issue than me, sorry :)

@chaim1989
Copy link

chaim1989 commented Nov 13, 2017 via email

@denzs
Copy link
Member

denzs commented Dec 4, 2017

I did encounter some changes in freeswitchs behaviour since 1.6.15, so you could try to use 1.6.13 (that worked for me a long time) to see if that changes anything...

Anyway... please provide a fs_cli trace with:

  • verbose=true (gofax.conf) and
  • sofia global siptrace on (fs_cli)
  • /log 7 (fs_cli)

@denzs
Copy link
Member

denzs commented Dec 4, 2017

I am able to reproduce your problem and i will open an issue in freeswitch (propably tomorrow) because from my point of view freeswitch should terminate the call after calling txfax when txfax is the only application triggered by originate...

But i can only reproduce the problem when the other side of the fax transmission is another gofaxip server without the missing hangup from #37 ...

Do you know anything about the receiving side in your scenario?

Because normally i would expect the other side to be interested in terminating the call after the transmission too ;)
If it actually is another gofaxip server, your problem should be gone if the fix from #37 is deployed on the receiving end...

@chaim1989
Copy link

chaim1989 commented Dec 5, 2017 via email

@denzs
Copy link
Member

denzs commented Dec 6, 2017

I just opened an issue in freeswitch:
https://freeswitch.org/jira/browse/FS-10824

If you have any further information feel free to add them to the issue!

@chaim1989
Copy link

Denzs thanks for taking care of it,
do you know any version of freeswitch that i should change to and get rid of this issue, it's driving me mad...

@denzs
Copy link
Member

denzs commented Dec 6, 2017

As mentioned before, i am using 1.6.15 without problems....

At this very moment i am building 1.6.16 and 1.6.17 to narrow it down...

In most cases i am using gofaxip with Patton Smartnode media-gateways, these devices do send a re-invite back to g711 after the fax transmissions which results in freeswitch (1.6.15) sending a
SIP/2.0 488 Not Acceptable Here followed by a hangup initiated by freeswitch.

-> this leads to the unsatisfying hangup cause INCOMPATIBLE_DESTINATION but at least it works!

I am not sure, how freeswitch 1.6.15 behaves when the other side doesnt send a re-invite...
I going to test that later...

I suggest you try 1.6.15, and if that doesnt help please provide a sofia siptrace log, then we have to check if we can do anything about it...

@chaim1989
Copy link

chaim1989 commented Dec 6, 2017 via email

@denzs
Copy link
Member

denzs commented Dec 6, 2017

After testing:

  • 1.6.16 behaves like 1.6.15 (re-invite -> 488 -> hangup)
  • 1.6.17 introduces the new behaviour and the channel hangs (re-invite -> 200 -> hanging channel)

@chaim1989
Copy link

I can confirm that fs 1.6.16 works as expected,

@denzs
Copy link
Member

denzs commented Dec 11, 2017

Do you have a comparable setup with Re-Invite to G711 after the transmission followed by 488 and hangup or do you have a "clean" call shutdown?

@denzs denzs mentioned this issue Mar 27, 2018
Closed
@vasyugan
Copy link

I am on 1.10.6 on Raspberrypi / Buster and unfortunately hanging up does not work as expected.

@vasyugan
Copy link

Wouldn't it be possible to fix the code of gofax.ip so that it also works with current versions of freeswitch? Staying on a legacy version forever doesn't sound like a good idea, I have to say.

@JonathanAldridge
Copy link

I am on 1.10.7 and getting the same issue of freeswitch not hanging up after the fax transmission completes.

I have an old system on 1.6 where it is working fine, on the same network (different RTP ports), so looks like an new issue.

@jigsp26
Copy link

jigsp26 commented Aug 18, 2022

@JonathanAldridge I have the same issue, with the same version. Can you please help me on this?

@luebke-dev
Copy link
Contributor

Can you provide us some logs @jigsp26 ?

@jigsp26
Copy link

jigsp26 commented Aug 18, 2022 •
edited
Loading

4b58dd51-f6eb-4287-bde1-71434a952524 2022-07-29 13:41:04.779861 91.70% [DEBUG] switch_core_state_machine.c:323 sofia/external/8175495330 Standard EXECUTE
4b58dd51-f6eb-4287-bde1-71434a952524 EXECUTE [depth=0] sofia/external/8175495330 txfax(/usr/local/freeswitch/storage/fax/mox3.accoonaglobal.com/75081/inbox/8175495330#1008-2022-07-29-13-39-21.tif)
4b58dd51-f6eb-4287-bde1-71434a952524 2022-07-29 13:41:04.779861 91.70% [DEBUG] mod_spandsp_fax.c:1610 Raw read codec activation Success L16 20000
4b58dd51-f6eb-4287-bde1-71434a952524 2022-07-29 13:41:04.779861 91.70% [DEBUG] switch_core_codec.c:223 sofia/external/8175495330 Push codec L16:100
4b58dd51-f6eb-4287-bde1-71434a952524 2022-07-29 13:41:04.779861 91.70% [DEBUG] mod_spandsp_fax.c:1628 Raw write codec activation Success L16
4b58dd51-f6eb-4287-bde1-71434a952524 2022-07-29 13:41:04.839775 91.70% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] sofia.c:7499 Channel sofia/external/8175495330 entering state [completing][200]
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] sofia.c:7509 Remote SDP:
a00e418d-1e75-42f5-8e82-8c464c614047 v=0^M
a00e418d-1e75-42f5-8e82-8c464c614047 o=Sonus_UAC 430162 331258 IN IP4 67.231.5.176^M
a00e418d-1e75-42f5-8e82-8c464c614047 s=SIP Media Capabilities^M
a00e418d-1e75-42f5-8e82-8c464c614047 c=IN IP4 67.231.5.91^M
a00e418d-1e75-42f5-8e82-8c464c614047 t=0 0^M
a00e418d-1e75-42f5-8e82-8c464c614047 m=audio 12126 RTP/AVP 0 101^M
a00e418d-1e75-42f5-8e82-8c464c614047 a=rtpmap:0 PCMU/8000^M
a00e418d-1e75-42f5-8e82-8c464c614047 a=rtpmap:101 telephone-event/8000^M
a00e418d-1e75-42f5-8e82-8c464c614047 a=fmtp:101 0-15^M
a00e418d-1e75-42f5-8e82-8c464c614047 a=ptime:20^M
a00e418d-1e75-42f5-8e82-8c464c614047
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] sofia.c:7499 Channel sofia/external/8175495330 entering state [ready][200]
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:3870 Set Codec sofia/external/8175495330 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_codec.c:111 sofia/external/8175495330 Original read codec set to PCMU:0
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:5973 sofia/external/8175495330 Set 2833 dtmf send payload to 101 recv payload to 101
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/external/8175495330] 172.31.36.81 port 19892 -> 67.231.5.91 port 12126 codec: 0 ms: 20
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:9089 sofia/external/8175495330 Set 2833 dtmf send payload to 101
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:9096 sofia/external/8175495330 Set 2833 dtmf receive payload to 101
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_media.c:9119 sofia/external/8175495330 Set rtp dtmf delay to 40
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [NOTICE] sofia.c:8683 Channel [sofia/external/8175495330] has been answered
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_channel.c:3950 (sofia/external/8175495330) Callstate Change DOWN -> ACTIVE
2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/external/8175495330] Peer UUID: a00e418d-1e75-42f5-8e82-8c464c614047
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [INFO] switch_channel.c:3270 sofia/external/8175495330 Flipping CID from "Accoona Global LLC" <16828002505> to "Outbound Call" <8175495330>
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] mod_commands.c:5169 (sofia/external/8175495330) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_state_machine.c:581 (sofia/external/8175495330) Running State Change CS_EXECUTE (Cur 8 Tot 96656)
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] switch_core_state_machine.c:647 (sofia/external/8175495330) State EXECUTE
a00e418d-1e75-42f5-8e82-8c464c614047 2022-07-29 13:41:04.899882 91.70% [DEBUG] mod_sofia.c:213 sofia/external/8175495330 SOFIA EXECUTE

After successfully send, calls will be send after 3 min

@JonathanAldridge
Copy link

JonathanAldridge commented Aug 18, 2022 via email •
edited
Loading

@vasyugan
Copy link

Can you provide us some logs @jigsp26 ?

I have the same problem. What logs do you need?

@denzs
Copy link
Member

denzs commented Aug 19, 2022

The reason for this issue is a change in behaviour of FreeSWITCH/mod_spandsp..

As i mentioned in #44 - the problems were introduced with FreeSWITCH 1.6.17.

I already opened a bug (> 4 years ago) in the old issue tracker, but as the issues were moved from Atlassian Tools to Github, the issue was closed...

But there already seem to be a "new version" of the bug: signalwire/freeswitch#1640

This definitely has to be fixed in FreeSWITCH/mod_spandsp.. i dont see any way to workaround this in an acceptable way :-/

@jigsp26
Copy link

jigsp26 commented Aug 25, 2022

Still the issue is open, I can't use any other version
I need STIR/SHAKEN and that is on this version only.
Please help me on this

@denzs
Copy link
Member

denzs commented Aug 26, 2022

As i already said.. this has to be fixed upstream inside of FreeSWITCH... :-/
If you depend on this, maybe think about asking SignalWires Consulting about fixing this for money?

@Brettk80
Copy link

Was a solution ever found for this issue with FreeSwtich? V 1.10.7 still seems to have it in some call cases.

@denzs
Copy link
Member

denzs commented Jan 16, 2023

Unfortunately, my last comment is still up to date... :-/

@Brettk80
Copy link

SO downgrading to 1.6.15 works correctly with t38?

@denzs
Copy link
Member

denzs commented Jan 19, 2023

1.6 should work right.. i know thats an unsatisfying answer :-/

@Brettk80
Copy link

Brettk80 commented Jan 19, 2023 via email

@denzs
Copy link
Member

denzs commented Jan 19, 2023

#31 (comment)

1.6.16 should be good

@Brettk80
Copy link

Brettk80 commented Jan 19, 2023 via email

@Brettk80
Copy link

Doesnt seem this can be compiled with AWS supported flavors of linux anymore. Any additional ideas?

@denzs
Copy link
Member

denzs commented May 12, 2023

@Brettk80 please open another issue for this and do not forget to add some information about the concrete problem :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug freeswitch
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests