Сколько времени asterisk переключается на T.38?

[Somerek]

При приеме факса по T.38 через Spandsp или Digium FAX Driver функцией ReceiveFax() сначала удаленный сторонний абонент слышит писк факса пониженной громкости 2-3 секунды, потом в логах появляются
== Using UDPTL TOS bits 184
== Using UDPTL CoS mark 5
и удаленный абонент слышит писк нормальной громкости и может начинаться прием факса.
Такая ситуация происходит при звонках через транки SIP-провайдера (ЭР-телеком) и FXO шлюз (Grandstream). Если принимаю факс с помощью IAXmodem - то сразу идет писк нормальной громкости, и факс может приниматься сразу. Как-нибудь можно победить эту паузу перед переключением на T.38?

[Somerek]

Пробовал настроить VentaFax MiniOffice на этого SIP-оператора - там все гудит сразу громко, значит проблема в астериске. По логам видно, что пауза 3с.

Код: Выделить всё

[2015-05-08 09:50:35] VERBOSE[10520][C-000002d5] pbx.c:     -- Executing [receive@fax-rx:18] ReceiveFAX("SIP/ertelecom3out-00000069", "/var/spool/asterisk/fax/Received by 322 2015-05-08 09-50.tif") in new stack
[2015-05-08 09:50:35] VERBOSE[10520][C-000002d5] res_fax.c:     -- Channel 'SIP/ertelecom3out-00000069' receiving FAX '/var/spool/asterisk/fax/Received by 322 2015-05-08 09-50.tif'
[2015-05-08 09:50:38] VERBOSE[10520][C-000002d5] netsock2.c:   == Using UDPTL TOS bits 184
[2015-05-08 09:50:38] VERBOSE[10520][C-000002d5] netsock2.c:   == Using UDPTL CoS mark 5

Факсовые сессии становятся видны только после этих строчек "Using UDPTL" в логе:

Код: Выделить всё

asterisk*CLI> fax show sessions

Current FAX Sessions:

Channel              Tech       FAXID      Type  Operation  State           File(s)                       
SIP/ertelecom3out-00 Spandsp    3          T.38  receive    Active          /var/spool/asterisk/fax/Received by 322 2015-05-08 11-58.tif

1 FAX sessions

[Somerek]

Попробовал ReceiveFAX с опцией d - ничего не изменилось, после receiving FAX ничего не добавилось. А у вас сразу факсовые сессии появляются после вызова ReceiveFAX()?

[Somerek]

Проверял на Asterisk 11.7.0, Asterisk 11.14.1.
Пауза происходит между строчками

Код: Выделить всё

channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second

и

Код: Выделить всё

channel.c: Auto-deactivating generator.

PRIME_BBCODE_SPOILER_SHOW PRIME_BBCODE_SPOILER: Полный лог

[2015-05-11 14:18:50] VERBOSE[8513][C-00000009] pbx.c: -- Executing [receive@fax-rx:16] ReceiveFAX("SIP/FXO8_6-0000000d", "/var/spool/asterisk/fax/Received by 72608584 2015-05-11 14-18.tif,d") in new stack
[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Context: fax-rx
Extension: receive
Priority: 16
Application: ReceiveFAX
AppData: /var/spool/asterisk/fax/Received by 72608584 2015-05-11 14-18.tif,d
Uniqueid: 1431343129.16


[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: FAXSTATUS
Value: FAILED
Uniqueid: 1431343129.16


[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: FAXPAGES
Value: 0
Uniqueid: 1431343129.16


[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: FAXSTATUS
Value: FAILED
Uniqueid: 1431343129.16

[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: FAXERROR
Value: INIT_ERROR
Uniqueid: 1431343129.16


[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: FAXSTATUSSTRING
Value: error starting fax session
Uniqueid: 1431343129.16


[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: LOCALSTATIONID
Value: Name
Uniqueid: 1431343129.16


[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: FAXPAGES
Value: 0
Uniqueid: 1431343129.16

[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: FAXERROR
Value: Channel Problems
Uniqueid: 1431343129.16


[2015-05-11 14:18:50] DEBUG[6639] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/FXO8_6-0000000d
Variable: FAXSTATUSSTRING
Value: Error before FAX transmission started.
Uniqueid: 1431343129.16


[2015-05-11 14:18:50] VERBOSE[8513][C-00000009] res_fax.c: -- Channel 'SIP/FXO8_6-0000000d' receiving FAX '/var/spool/asterisk/fax/Received by 72608584 2015-05-11 14-18.tif'
[2015-05-11 14:18:50] DEBUG[8513][C-00000009] res_fax.c: Reserving a FAX session from 'Spandsp FAX Driver'.
[2015-05-11 14:18:50] DEBUG[8513][C-00000009] res_fax.c: Selected FAX technology module (Spandsp FAX Driver) does not support reserving sessions.
[2015-05-11 14:18:50] DEBUG[8513][C-00000009] channel.c: Set channel SIP/FXO8_6-0000000d to write format slin
[2015-05-11 14:18:50] DEBUG[8513][C-00000009] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[2015-05-11 14:18:50] DEBUG[8513][C-00000009] dsp.c: tone 1100, Ew=1.59E+05, Et=4.58E+07, s/n= 0.00

[2015-05-11 14:18:51] DEBUG[6639] manager.c: Examining event:
Event: RTCPSent
Privilege: reporting,all
To: 192.168.3.7:5029
OurSSRC: 1109999591
SentNTP: 1431343131.3892875264
SentRTP: 72640
SentPackets: 455
SentOctets: 72800
ReportBlock:
FractionLost: 0
CumulativeLoss: 0
IAJitter: 0.0001
TheirLastSR: 0
DLSR: 36891.9500 (sec)


[2015-05-11 14:18:53] DEBUG[8513][C-00000009] dsp.c: tone 1100, Ew=1.52E+05, Et=3.82E+06, s/n= 0.04
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] channel.c: Auto-deactivating generator
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] channel.c: Set channel SIP/FXO8_6-0000000d to write format ulaw
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] res_fax.c: Negotiating T.38 for receive on SIP/FXO8_6-0000000d
[2015-05-11 14:18:53] VERBOSE[8513][C-00000009] netsock2.c: == Using UDPTL TOS bits 184
[2015-05-11 14:18:53] VERBOSE[8513][C-00000009] netsock2.c: == Using UDPTL CoS mark 5
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] chan_sip.c: Setting NAT on UDPTL to Off
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] chan_sip.c: T38 state changed to 1 on channel SIP/FXO8_6-0000000d
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] netsock2.c: Splitting '192.168.3.7:5070' into...
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] netsock2.c: ...host '192.168.3.7' and port '5070'.
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] chan_sip.c: Done building SDP. Settling with this capability: (nothing)
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] chan_sip.c: Initializing already initialized SIP dialog 652d23f419c21d793ba5ee830fdd1326@192.168.3.181:5060 (presumably reinvite)
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.3.7:5070
[2015-05-11 14:18:53] DEBUG[8513][C-00000009] dsp.c: tone 1100, Ew=3.29E+05, Et=2.88E+06, s/n= 0.13
[2015-05-11 14:18:53] DEBUG[6629] chan_sip.c: = Looking for Call ID: 652d23f419c21d793ba5ee830fdd1326@192.168.3.181:5060 (Checking To) --From tag as22d7ff47 --To-tag bd444d4101147111
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: Acked pending invite 103
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: Stopping retransmission on '652d23f419c21d793ba5ee830fdd1326@192.168.3.181:5060' of Request 103: Match Found
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: SIP response 200 to RE-invite on outgoing call 652d23f419c21d793ba5ee830fdd1326@192.168.3.181:5060
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: Processing session-level SDP o=system 8006 8002 IN IP4 192.168.3.7... OK.
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED.
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] netsock2.c: Splitting '192.168.3.7' into...
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] netsock2.c: ...host '192.168.3.7' and port ''.
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.3.7... OK.
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: FaxVersion: 0
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: Processing media-level (image) SDP a=T38FaxVersion:0... OK.
[2015-05-11 14:18:53] DEBUG[6629][C-00000008] chan_sip.c: T38MaxBitRate: 9600