VoiceGuide IVR Software Main Page
Jump to content

Problem Receiving Fax

Recommended Posts

Hello,

 

Today we started to use a new server, using the DMV300BTEPEQ.

During the morning was everything working fine.

Almost 60 minutes ago the application stopped working.

The script runs until the fax signal, and when goes to start to receive the fax, the call is broken.

I saw in the log some messages from the VG like this:

 

"

131620.529 6 rv dbg RetrieveRv strRvStoreRetrieveRvValuesFrom=[PathSysVoice]{C:\Program Files\VoiceGuide\system\voice\}[PathApp]{C:\Program Files\VoiceGuide\}[PathDataVm]{C:\Program Files\VoiceGuide\data\}[PathVgSys]{C:\Program Files\VoiceGuide\system\}[scriptPath]{C:\Program Files\VoiceGuide\ScriptsProducao\}[scriptsPath]{C:\Program Files\VoiceGuide\ScriptsProducao\}[$RV_STARTTIME]{2011-06-29 13:15:29}[$RV_DEVICEID]{96}[DlgcVoice]{dxxxB6C4}[DlgcNetwork]{dtiB1T24}[$RV_CIDNAME]{}[$RV_DNIS]{0508}[DNIS]{0508}[PathApp]{C:\Program Files\VoiceGuide\}[scriptPath]{C:\Program Files\VoiceGuide\ScriptsProducao\}[scriptsPath]{C:\Program Files\VoiceGuide\ScriptsProducao\}[$RV_CIDNUMBER]{1125337925}[salva_numero_ResultReturn]{success}[valida_entrada_Input]{0508}[valida_entrada]{508}[scriptEnd_Time]{2011-06-29 13:15:29}[scriptEnd_Goto_Script]{BRA\FaxRxFinasa.vgs}[scriptEnd_Goto_Module]{}[scriptStart_Time]{2011-06-29 13:15:29}[scriptStart_CalledFrom_Script]{C:\Program Files\VoiceGuide\ScriptsProducao\FaxTeste.vgs}[scriptStart_CalledFrom_Module]{script_bradesco}[scriptsPath]{C:\Program Files\VoiceGuide\ScriptsProducao\BRA\}[CapturaTipoProduto]{2}[NumeroAgencia]{2938}[NumeroAgencia_PathTaken]{success}[NumeroContaCorrente]{11868}[NumeroContaCorrente_PathTaken]{success}[NumeroContrato]{35584420}[NumeroContrato_PathTaken]{success}[statusAgenciaConta]{OK}[VerificaAgenciaConta_Input]{OK}[VerificaAgenciaConta]{OK}[AgenciaContaOK_ResultReturn]{success}

131620.529 6 rv dbg RetrieveRv strRvListRefIn strIn.Substring(0, 41)C:\faxrecebidoBRADESCO\BRAPO_355844202938, strIn.Substring(64+1)=_110629131620.tif

131620.529 6 rv dbg RetrieveRv strRvListRefIn slRvPosInRvStr1=1161, lRvPosInRvStr2=1167

131620.529 6 rv dbg RetrieveRv strRvListRefIn RV value=11868

131620.529 6 rv dbg RvProcessAndReplace_RvPrefix_OnePass lRvPos=-1

131620.529 6 96 24 rv replace end: [C:\faxrecebidoBRADESCO\BRAPO_35584420293811868_110629131620.tif]

131620.529 6 96 24 rv add [RxFaxPonte]{C:\faxrecebidoBRADESCO\BRAPO_35584420293811868_110629131620.tif}

131620.529 6 96 24 state [RxFaxPonte] Receiving Fax C:\faxrecebidoBRADESCO\BRAPO_35584420293811868_110629131620.tif

131620.529 6 96 24 ReceiveFaxStart ktTel_Fax_Rx_Start_Enqueue call [C:\faxrecebidoBRADESCO\BRAPO_35584420293811868_110629131620.tif]

131620.529 6 96 24 qTel add cmd_Fax_Rx_Start [0,0,0,0,0][C:\faxrecebidoBRADESCO\BRAPO_35584420293811868_110629131620.tif|||********|]

131620.529 6 96 24 t timer set 3600 sec : EV_TIMEOUT_HANGUP

131620.529 7 96 24 qTel run cmd_Fax_Rx_Start

131620.529 6 96 24 timer set completed lTimeLeft250msUnits=14400, iTimeoutCode=9001

131620.529 7 96 24 ev Dialogic 0,TFX_FAXERROR, crn=6020060, -2,0,0,Fax_Rx_Start_Now_DelayedCall,,

131620.529 7 96 24 qScr add evScriptEvent 0 TFX_FAXERROR

131620.529 6 96 24 qScr run evScriptEvent sCode=[TFX_FAXERROR] iActionID=0, crn=6020060[-2|0|0|0|0][Fax_Rx_Start_Now_DelayedCall|||||]

131620.529 6 96 24 scriptevent TFX_FAXERROR param1:Fax_Rx_Start_Now_DelayedCall, param2:, param3:

131620.529 6 96 24 LsFaxRx TFX_FAXERROR -2 Fax_Rx_Start_Now_DelayedCall

131620.529 6 96 24 path {TFX_FAXERROR} not found

131620.529 6 96 24 HangupCall, source=LsFaxRx Fax_Rx_Start_Now_DelayedCall, WorkModeScript=Running_Normal, yLineStateAppPov=[Connected], lPlayId=0, lRecId=0

131620.529 6 96 24 moduleTitle=[RxFaxPonte]

131620.529 6 96 24 ScriptWorkingMode set Stopping, (called from HangupCall)

131620.529 6 96 24 ls set Disconnect_Pending (scriptstate=LS_ENDINGCALL)

131620.529 6 96 24 state Hanging up... [LsFaxRx Fax_Rx_Start_Now_DelayedCall]

131620.529 6 96 24 rv add [Hangup Source]{LsFaxRx Fax_Rx_Start_Now_DelayedCall}

131620.529 6 96 24 GoOnHoook_IssueDropCall start (hCall_crn=6020060)

131620.529 6 96 24 t timer set 10 sec : EV_TIMEOUT_WAITFORIDLEAFTERDropCall

131620.529 6 96 24 timer set completed lTimeLeft250msUnits=40, iTimeoutCode=9101

131620.529 6 96 24 qTel add cmd_DropCall [0,0,0,0,0][|||********|]

131620.529 6 96 24 GoOnHoook_IssueDropCall end

131620.529 7 96 24 qTel run cmd_DropCall

"

 

In this log I can see the messages:

131620.529 6 96 24 scriptevent TFX_FAXERROR param1:Fax_Rx_Start_Now_DelayedCall, param2:, param3:

131620.529 6 96 24 LsFaxRx TFX_FAXERROR -2 Fax_Rx_Start_Now_DelayedCall

131620.529 6 96 24 path {TFX_FAXERROR} not found

 

What can be happening??

 

 

Regards

log VG.zip

Share this post


Link to post

Looks like Dialogic is replying with "err=9:Unknown error" every time it is requested to commence fax receive.

 

Can you please .ZIP up and post traces of the ktTel trace which covers the time when fax receive was working. This will let us see what happened at time when fax receive stopped working.

 

Dialogic traces would be helpful here as well.

Share this post


Link to post

Attached is the last files that where generated.

Before the last test i deleted a lot of log files, but I think that in these files you have the information that you need.

 

regards

 

Cláudio Schmidt

 

tmp_log.zip

Share this post


Link to post

We would need to see the log files that capture the time the problem started.

 

Probably best to just restart the system and when it fails again then .ZIP up the ktTel log that covers that time and post it here.

Share this post


Link to post

Hello,

 

Today occured the same problem.

Attached are the logs.

The first ocurrence os this error I found at 14:04.

("140440.668 4056 12 r Dialogic TFX_FAXERROR 0 (-2 0 0 Fax_Rx_Start_Now_DelayedCall )")

 

Can you understand what kind of problem is occuring?

 

 

http://www.watchdoc.com.br/wdpagamento/Documentos/vgEngine1.zip

 

http://www.watchdoc.com.br/wdpagamento/Documentos/ktTel.zip

 

Regards

Share this post


Link to post

Just to give more details, I stoped and started the board in DCM and now it's working fine.

Share this post


Link to post

We had a look at the trace file and cannot see any apparent causes at this stage. Dialogic just seems to suddenly start erroring on commencement of fax receive.

 

Are you able to post the Dialogic RTF logs as well? This would be the next place to look at.

 

Does this problem seem to occur after some days of constant operation? Maybe as a temporary workaround try scheduling an automated system restart every 24 hours (eg at 4am) and see if this reduces the incidence of issues.

 

After looking at RTF logs we will try to setup a similar system here to see if we can replicate the issue. Are you able to post the script used on this system?

How many calls does this system get daily? how many faxes daily does it receive?

Which version of Dialogic drivers is used on this system?

 

 

 

 

140440.653  4056  12 fn    Fax_Rx_Start(sFile=C:\faxrecebido\BV_299137059_110704140440.tif, sOptions=)
140440.653  4056  12       Fax_Rx_Start(sFile=[C:\faxrecebido\BV_299137059_110704140440.tif], sOptions=[])
140440.653  4056  12       fax   Fax_Rx_Start_Now begin
140440.653  4056  12       fax   Clean_iottFax_chain
140440.653  4056  12       Route_FaxResource_To_GCdevice begin. dxxxB9C3:14 to dtiB1T3:12 (hli->ct_devinfo_dx.ct_devfamily=5)
140440.653  4056  13       fx_listen() to ts=27 (gc_get) ok
140440.653  4056  12       fx_getxmitslot(13) call
140440.653  4056  12       gc_Listen to ts=62 call
140440.653  4056  12       gc_Listen to ts=62 (fx_get) ok
140440.653  4056  12 ERROR fax   fx_rcvfax(14, DF_RX) failed => -1, err=9:Unknown error, hli=0B149D38
140440.668  4056  12 r     Dialogic  TFX_FAXERROR 0 (-2 0 0 Fax_Rx_Start_Now_DelayedCall  )

Share this post


Link to post

Hello,

 

Attached is the Dialogic logs.

 

There is some scripts. I attached two of them.

The script FaxTeste is the first that is executed. This script reads the MCDU and calls another script. In all the scripts that are executed occurs the same problem. I sent the script FaxRxDemo that is executed in some situations.

 

This board started to work on Wednesday. In the first day we had the problem the first time.

In Thursday we restarted the system and it's worked fine until yesterday, when the problem occured again.

 

In Thursday we received almost 7000 calls in this board, receiving almost 10.000 fax pages.

 

 

 

Dialogic_log.zip

FaxTeste.vgs

FaxRxDemo.vgs

Share this post


Link to post

Can you please post the ktTel log from 4th July (or just the excerpt of it that covers time from 1pm till 4pm) ?

Share this post


Link to post

BTW. Please see attached file for recommended approach to DNIS based switching. Jumps to other scripts can be made directly in the Path expression. This is quicker and uses up less resources then what is used when a VBScript is module is used.

FaxTeste_new.vgs

Share this post


Link to post

thanks for the tip.

I will change de production script.

 

And about the problem, could you find any clue?

 

regards

Share this post


Link to post

Can you please post the ktTel log from 4th July (or just the excerpt of it that covers time from 1pm till 4pm). We need these to see what happened.

Share this post


Link to post

Hello,

 

Could you find what is happening?

This problem is occuring 2 or 3 times a day, and I have to stop the VG and the DCM and start everithing again.

The problem is that sometimes I just know that occured this problem when the user calls to me talking that the system isn't working.

 

Regards

Share this post


Link to post

The problems seem to be happening at Dialogic level. We are contacting Dialogic to resolve this.

 

In meantime it is possible to create at script level some sort of an alert that fires whenever fax receive problem is detected. eg: an email being sent out when fax receive module returns an error immediately after starting.

 

Or we can even start a task that does a Dialogic and VoiceGuide service restart after such a problem is detected.

 

Would you like to setup such an alert or automated restart system as a temporary workaround?

Share this post


Link to post

Can you please advise what Service Update version of the SR6.0 is installed on this system.

Share this post


Link to post

Hello,

 

How can I see wich version f SU is installed?

 

I prefer to receive an alert and I make the manual restart.

 

 

 

Share this post


Link to post

To check Service Update version open the Dialogic Configuration Manager and go to Help->About menu, or post the first 10 lines or so of the ktTel trace logged immediately after VoiceGuide service restart.

 

The attached script has been modified to show how to detect that the Fax receive attempt took too little time. Please see the 3 modules added around the module "RxFax". Other modules which do the fax reception will need to have similar modules added around them.

FaxRxFinasa_modified.vgs

Share this post


Link to post

Attached is the screen from the DCM.

 

Bellow are the lines from the log:

 

185241.719 5764 ------------------------------------------------------------------------------

185241.719 5764 fn LogLevels 10, root=[C:\Program Files\VoiceGuide\], log=[C:\Program Files\VoiceGuide\log\], suffix=[_ktTel.txt]

185242.906 5964 fn Initialize(sHomePath=C:\Program Files\VoiceGuide\, sConfigXml_ktTel=, sConfigXml_ktTts=, sConfigXml_Others)

185242.906 5964 CTelDialogic::Constructor trace: CTelDialogic=>[CTelDialogic: m_pTelProxy=0101D708][CTelDialogic: m_pTelProxy=06D28308]. this CTelDialogic instance's m_pTelProxy=0101D708

185242.906 5964 CTelProxy::Initialize start sHomePath=[C:\Program Files\VoiceGuide\] sConfigXml_ktTel=[] DlgcServiceType=[], timeout=300

185242.906 5964 CTelProxy::Constructor trace: [CTelProxy pClient_PassedIn=06CE002C, this=0101D708][CTelProxy pClient_PassedIn=06CE000C, this=06D28308]. this CTelProxy instance this=0101D708

185242.906 5964 ------------------------------------------------------------------------------

185242.906 5964 ktTel_SR60 DLL v7.1.0, created: Jun 16 2010, 14:53:52

185242.906 5964 start at 0713 185242.906

185242.906 5964 ------------------------------------------------------------------------------

post-4054-131059414466_thumb.jpg

Share this post


Link to post

The Service Update version on this system is 239. This is the right service update for use with the version of VoiceGuide that is installed on the system (VG version is 1 year old).

 

You could try updating system to latest version of VoiceGuide and the newer Dialogic drivers that are matched with it (Dialogic drivers for VoiceGuide that are downloadable from our WWW Downloads page).

Share this post


Link to post

Would not expect any major issues with the upgrade.

 

You would need to first uninstall the Dialogic drivers (do not save any configuration) then install new Dialogic drivers and then install new version of VoiceGuide.

 

Before starting the Dialogic service please also start Dialogic's DebugAngel service. Please see:

http://www.dialogic.com/support/helpweb/helpweb.aspx/890/obtaining_dm3_hmp_firmware_message_logging/DM3

and Section 12 of: http://www.dialogic.com/manuals/docs/dm3_diagnostics_win_v7.pdf

 

Then when problem occurs please post:

- VoiceGuide's ktTel trace

- Dialogic's RTF logs

- Dialogic's DebugAngel logs

- output of Dialogic's devmapdump applet

Share this post


Link to post

Thanks for logs.

 

Response from Dialogic:

 

 
Inorder to investigate this issue in a detailed manner. Please enable the following log levels in the RTFConfig file found in the cfg directory of the dialogic folder.

<!-- DM3 VOICE -->
<Module family="DM3,HMP" name="dm3voice" state="1" technology="media">
  <MLabel name="DEBG" state="1"/>
  <MLabel name="INFO" state="1"/>
  <MLabel name="WARN" state="1"/>
  <MLabel name="APPL" state="1"/>
  <MLabel name="EXCE" state="1"/>
  <MLabel name="ERR1" state="1"/>
  <MLabel name="ERR2" state="1"/>
  <MLabel name="EINF" state="1"/>
</Module>
<!-- DM3 CC -->
<Module family="DM3,HMP" name="dm3cc" state="1" technology="media">
  <MLabel name="DEBG" state="1"/>
  <MLabel name="INFO" state="1"/>
  <MLabel name="WARN" state="1"/>
  <MLabel name="APPL" state="1"/>
  <MLabel name="EXCE" state="1"/>
  <MLabel name="ERR1" state="1"/>
  <MLabel name="ERR2" state="1"/>
  <MLabel name="EINF" state="1"/>
</Module>
<!-- DM3 FAX -->
<Module family="DM3,HMP" name="dm3fax" state="1" technology="fax">
  <MLabel name="DEBG" state="0"/>
  <MLabel name="INFO" state="0"/>
  <MLabel name="WARN" state="0"/>
  <MLabel name="APPL" state="0"/>
  <MLabel name="EXCE" state="1"/>
  <MLabel name="ERR1" state="1"/>
  <MLabel name="ERR2" state="1"/>
  <MLabel name="EINF" state="1"/>
</Module>

Then save the file, issue the below commands for the configuration changes to take effect

rtftool pause
rtftool clean
rtftool reload
rtftool resume

Now try restarting the dialogic services via the DCM.
Oonce the failure is seen collect the RTF logs by running the "its_sysinfo.exe" found in the bin directory of the dialogic folder and send across the same to us for further analysis.

Share this post


Link to post

From Dialogic:

I would like to have the devmapdunp also in this case. You can run the following command in the console window..
devmapdump > <filename.txt>


also enable the following in the RTF Config file
<!-- Global Call -->
<!-- LIBGC -->
<Module family="DM3,SPWR,HMP" name="gc" state="1" technology="PSTN">
  <MLabel name="INTF" state="1"/>
  <MLabel name="DEBG" state="1"/>
  <MLabel name="INFO" state="1"/>
  <MLabel name="WARN" state="1"/>
  <MLabel name="APPL" state="1"/>
  <MLabel name="EXCE" state="1"/>
  <MLabel name="ERR1" state="1"/>
</Module>

<!-- Voice Library -->
<Module family="SPWR" name="spwrvoice" state="1" technology="media">
  <MLabel name="DEBG" state="1"/>
  <MLabel name="INFO" state="1"/>
  <MLabel name="APPL" state="1"/>
  <MLabel name="WARN" state="1"/>
  <MLabel name="ERR1" state="1"/>
  <MLabel name="EXCE" state="1"/>
</Module>
<!-- VOICE LIBRARY -->
<Module family="DM3" name="libdxxmt.dll" state="1" technology="media">
  <MLabel name="Internal_Entry" state="1"/>
  <MLabel name="Internal_Exit" state="1"/>
  <MLabel name="Internal_Entry_Args" state="1"/>
  <MLabel name="Internal_Exit_Args" state="1"/>
  <MLabel name="Warning" state="1"/>
  <MLabel name="External_Entry" state="1"/>
  <MLabel name="External_Exit" state="1"/>
  <MLabel name="External_Entry_Args" state="1"/>
  <MLabel name="External_Exit_Args" state="1"/>
</Module>
Save the config file and carry out the procedure as mentioned in the previous mail and send us the logs..

 

Alos they ask that system's Dialogic drivers be changed. Will provide download link by email.

Share this post


Link to post

Response from Dialogic:

 

Thanks for the logs, but unfortunately we don't have much detailed logs that we expected. 
Can you confirm with the customer whether the RTFconfig file was reloaded using the rtftool reload command and application started after reloading the config file. 
If the RTF logs are overwritten it would be worth increasing the file size and the number files also in the RTFconfig  file. 
Also can you ask the customer to get the Devmapdump after starting the board since the dump sent by the customer looks like it was taken when the board was stopped.

 

Can you please advise whether:

 

RTFconfig file was reloaded using the rtftool

 

and application started after reloading the config file.

 

do the Devmapdump after starting the board

Share this post


Link to post

Hello,

 

I started the rtfconfig using rtftool.

Next time that I will need to start the server, I will execute the devmapdump. I have undestood that I needed to execute that comando after occured the problem.

 

The next time that the problem occurs, I send the logs again.

Share this post


Link to post

The problem just posted does not seem to be fax related.

 

In this trace we see that every fax receive that was started did complete OK

ktTel trace shows last fax receive was started at 10:24:51, and last fax receive completed at 10:27:59

 

102451.184 4812 20 fn Fax_Rx_Start(sFile=C:\faxrecebido\BV_883924579_110801102451.tif, sOptions=)

...

102542.824 5272 20 fax Received 1 pages at speed 9600, resln 98, width 1728 [C:\faxrecebido\BV_883924579_110801102451.tif]

102543.465 5272 112 fax Received 5 pages at speed 9600, resln 98, width 1728 [C:\faxrecebido\BV_960224445_110801102207.tif]

102543.730 5272 16 fax Received 2 pages at speed 9600, resln 98, width 1728 [C:\faxrecebidoBRADESCO\BRA_36129131_110801102415.tif]

102547.309 5272 52 fax Received 9 pages at speed 14400, resln 98, width 1728 [C:\faxrecebido\BV_519797648_110801102215.tif]

102559.371 5272 56 fax Received 2 pages at speed 14400, resln 196, width 1728 [C:\faxrecebidoBRADESCO\BRA_36105749_110801102347.tif]

102612.887 5272 120 fax Received 4 pages at speed 9600, resln 98, width 1728 [C:\faxrecebidoBRADESCO\BRAPO_3597872835679889_110801102321.tif]

102621.902 5272 92 fax Received 4 pages at speed 9600, resln 98, width 1728 [C:\faxrecebido\BV_439132948_110801102314.tif]

102626.902 5272 80 fax Received 7 pages at speed 14400, resln 98, width 1728 [C:\faxrecebido\BV_884654382_110801102109.tif]

102646.996 5272 108 fax Received 4 pages at speed 9600, resln 98, width 1728 [C:\faxrecebidoBRADESCO\BRA_36092451_110801102426.tif]

102707.480 5272 32 fax Received 3 pages at speed 9600, resln 98, width 1728 [C:\faxrecebido\BV_874112703_110801102319.tif]

102759.573 5272 44 fax Received 10 pages at speed 9600, resln 98, width 1728 [C:\faxrecebidoBRADESCO\BRALO_97523331000148_110801101849.tif]

 

There are no fax errors anywhere in the trace.

 

We are however seeing many "call control library specific failure" errors - these are seen throughout the ktTel log and get more frequent as the day goes on. eg:

 

102626.355 5272 72 gc_ResultValue: event 0x826 received on ldev: 72 - Event caused by call control library specific failure

 

these errors result in call disconnection.

 

indeed before the 10:40 restart we are seeing a lot of these errors being reported in the ktTel trace.

 

 

Dialogic Support noted that you have two DMV300BTEPE cards in this system:

 

DMV300BTEPE #0 in slot 3/0

FCDFileName

--Value: gml5_ssbe_1_net5.fcd

PCDFileName

--Value: gml5_ssbe_1_net5.pcd

OffDiagPCDFileName

--Value: mercury_i960hd_diag.pcd

PCDFileDesc

--Value: DMV300BTEPE ( 30 Network , 30 Basic Voice , 30 fax ] )

 

and

 

DMV300BTEPE #1 in slot 2/0

FCDFileName

--Value: ssbe_default.fcd

PCDFileName

--Value: ssbe_default.pcd

OffDiagPCDFileName

--Value: mercury_i960hd_diag.pcd

PCDFileDesc

--Value: DMV300BTEPE ( 30 voice [ CSP , true spch , FSK ] , 12 fax , 30 Conf [ DTMF TC ] )

 

Are these cards linked by the CT-Bus cable? (they should be)

 

 

Dialogic Support also noted that the cards' clocking is setup as Master.

Did you change the clocking settings at all for thee cards?

Does the E1 attached to this card come from your Switch or from Telcos Switch?

Can you find out if the Switch supplying this T1 is set as the clocking Master or a Slave?

Share this post


Link to post

If you do not have the CT-Bus cable to connect these cards together then please just remove the second card.

 

Probably best to remove the second card anyway, and concentrate on just getting a stable system working with one card. Once we have a stable system here then we can add the second card and CT-Bus cable etc.

 

Right now the VoiceGuide license on this system is for 30 channels only, all of which are opened on the first card only anyway.

Share this post


Link to post

The second board is disabled.

We are still waiting the E1 to buy the licenses and enable the board.

The problem started before we installed the second board.

post-4054-13123844499_thumb.jpg

Share this post


Link to post

We still have the problem every day.

Somy moments I can't stop other activities to get the logs.

 

The last log that I get are in the link bellow;

http://www.watchdoc.com.br/wdpagamento/Documentos/Logs_20110824.zip

 

In the file 0824_0947 of the VoiceGuide logs there are many situations with the problem.

 

I tried to get the ISDN logs but I couldn't find the files that where generated. I just found the log from this trace.

Should I execute this commando before stop the VG and the Dialogic or after stop them?

 

Regards

 

 

 

Share this post


Link to post

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
×