CMU Sphinx / Forums / Help: Asterisk+Unimrcp+pocketsphinx

Hi, i've been trying to integrate pocketsphinx with asterisk with no luck. I
followed the tutorial http://code.google.com/p/unimrcp/wiki/PocketSphinxPlugi
n. and

[url]http://code.google.com/p/unimrcp/wiki/asteriskUniMRCP[/url]

, managed to install pocketsphinx and sphinxbase 0.7 with asterisk 1.6.2.13,
unimrcp 1.0.0.

I have the default configuration and this is what i get:
- On Unimrcp server log:

2011-09-23 10:41:16:386816 [INFO]   Init Decoder <8b3621dd70ec47d7@pocketsphinx>
INFO: cmd_ln.c(691): Parsing command line:
\
        -alpha 0.97 \
        -dither yes \
        -doublebw no \
        -nfilt 31 \
        -ncep 13 \
        -lowerf 200 \
        -upperf 3500 \
        -nfft 256 \
        -wlen 0.0256 \
        -transform legacy \
        -feat 1s_c_d_dd \
        -agc none \
        -cmn current \
        -varnorm no

Current configuration:
[NAME]          [DEFLT]         [VALUE]
-agc            none            none
-agcthresh      2.0             2.000000e+00
-alpha          0.97            9.700000e-01
-ceplen         13              13
-cmn            current         current
-cmninit        8.0             8.0
-dither         no              yes
-doublebw       no              no
-feat           1s_c_d_dd       1s_c_d_dd
-frate          100             50
-input_endian   little          little
-lda
-ldadim         0               0
-lifter         0               0
-logspec        no              no
-lowerf         133.33334       2.000000e+02
-ncep           13              13
-nfft           512             256
-nfilt          40              31
-remove_dc      no              no
-round_filters  yes             yes
-samprate       16000           8.000000e+03
-seed           -1              -1
-smoothspec     no              no
-svspec
-transform      legacy          legacy
-unit_area      yes             yes
-upperf         6855.4976       3.500000e+03
-varnorm        no              no
-verbose        no              no
-warp_params
-warp_type      inverse_linear  inverse_linear
-wlen           0.025625        2.560000e-02

INFO: acmod.c(242): Parsed model-specific feature parameters from ../data/communicator/feat.params
INFO: fe_interface.c(289): You are using the internal mechanism to generate the seed.
INFO: feat.c(684): Initializing feature stream to type: '1s_c_d_dd', ceplen=13, CMN='current', VARNORM='no', AGC='none'
INFO: cmn.c(142): mean[0]= 12.00, mean[1..12]= 0.0
INFO: mdef.c(520): Reading model definition: ../data/communicator/mdef
INFO: bin_mdef.c(173): Allocating 104160 * 8 bytes (813 KiB) for CD tree
INFO: tmat.c(205): Reading HMM transition probability matrices: ../data/communicator/transition_matrices
INFO: acmod.c(117): Attempting to use SCHMM computation module
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/communicator/means
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/communicator/variances
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(354): 44589 variance values floored
INFO: acmod.c(119): Attempting to use PTHMM computation module
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/communicator/means
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/communicator/variances
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(354): 44589 variance values floored
INFO: ptm_mgau.c(800): Number of codebooks exceeds 256: 4153
INFO: acmod.c(121): Falling back to general multi-stream GMM computation
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/communicator/means
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/communicator/variances
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(354): 44589 variance values floored
INFO: ms_senone.c(160): Reading senone mixture weights: ../data/communicator/mixture_weights
INFO: ms_senone.c(211): Truncating senone logs3(pdf) values by 10 bits
INFO: ms_senone.c(218): Not transposing mixture weights in memory
INFO: ms_senone.c(277): Read mixture weights for 4153 senones: 1 features x 64 codewords
INFO: ms_senone.c(331): Mapping senones to individual codebooks
INFO: ms_mgau.c(122): The value of topn: 4
INFO: dict.c(306): Allocating 133345 * 20 bytes (2604 KiB) for word entries
INFO: dict.c(321): Reading main dictionary: ../data/default.dic
INFO: dict.c(212): Allocated 975 KiB for strings, 1606 KiB for phones
INFO: dict.c(324): 129247 words read
INFO: dict.c(330): Reading filler dictionary: ../data/communicator/noisedict
INFO: dict.c(212): Allocated 0 KiB for strings, 0 KiB for phones
INFO: dict.c(333): 3 words read
INFO: dict2pid.c(396): Building PID tables for dictionary
INFO: dict2pid.c(404): Allocating 51^3 * 2 bytes (259 KiB) for word-initial triphones
INFO: dict2pid.c(131): Allocated 31416 bytes (30 KiB) for word-final triphones
INFO: dict2pid.c(195): Allocated 31416 bytes (30 KiB) for single-phone word triphones
INFO: fsg_search.c(145): FSG(beam: -1080, pbeam: -1080, wbeam: -634; wip: -26, pip: 0)
INFO: jsgf.c(546): Defined rule: <digits.g00000>
INFO: jsgf.c(546): Defined rule: PUBLIC <digits.numbers>
INFO: fsg_model.c(213): Computing transitive closure for null transitions
INFO: fsg_model.c(264): 2 null transitions added
ERROR: "fsg_search.c", line 332: The word 'two' is missing in the dictionary
2011-09-23 10:41:25:119856 [WARN]   Failed to Init Decoder <8b3621dd70ec47d7@pocketsphinx>
2011-09-23 10:41:25:120288 [INFO]   Process DEFINE-GRAMMAR Response <8b3621dd70ec47d7@speechrecog> [2]
2011-09-23 10:41:25:120469 [INFO]   Send MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:51440 [112 bytes]
MRCP/2.0 112 2 407 COMPLETE
Channel-Identifier: 8b3621dd70ec47d7@speechrecog
Completion-Cause: 000 success


2011-09-23 10:41:25:156725 [INFO]   TCP/MRCPv2 Peer Disconnected 127.0.0.1:1544 <-> 127.0.0.1:51440
2011-09-23 10:41:25:157822 [INFO]   Receive SIP Event [nua_i_bye] Status 200 Session Terminated
2011-09-23 10:41:25:157860 [INFO]   Receive SIP Event [nua_i_state] Status 200 Session Terminated
2011-09-23 10:41:25:157874 [NOTICE] SIP Call State 0xa6960c8 [terminated]
2011-09-23 10:41:25:157898 [INFO]   Receive SIP Event [nua_i_terminated] Status 200 Session Terminated
2011-09-23 10:41:25:158209 [INFO]   Deactivate Session 0xa6960c8 <8b3621dd70ec47d7>
2011-09-23 10:41:25:158238 [INFO]   Terminate Session 0xa6960c8 <8b3621dd70ec47d7>
2011-09-23 10:41:25:158269 [INFO]   Close Channel <8b3621dd70ec47d7@pocketsphinx>
2011-09-23 10:41:25:158284 [NOTICE] Remove Session <8b3621dd70ec47d7>
2011-09-23 10:41:25:158648 [INFO]   Remove Control Channel <8b3621dd70ec47d7@speechrecog> [0]
2011-09-23 10:41:25:158706 [INFO]   Close RTP Receiver 127.0.0.1:5004 <- 127.0.0.1:4006 [r:0 l:0 j:0 d:0 i:0]
2011-09-23 10:41:25:158720 [INFO]   Remove RTP Session 127.0.0.1:5004
2011-09-23 10:41:25:159025 [NOTICE] Destroy TCP/MRCPv2 Connection 127.0.0.1:1544 <-> 127.0.0.1:51440
2011-09-23 10:41:25:159052 [INFO]   Session Terminated 0xa6960c8 <8b3621dd70ec47d7>
2011-09-23 10:41:25:159095 [NOTICE] Destroy Session <8b3621dd70ec47d7>
exit
2011-09-23 10:51:16:254075 [INFO]   Terminate Task [MRCP Server]
2011-09-23 10:51:16:254212 [INFO]   Close Engine [Recorder-1]
2011-09-23 10:51:16:254230 [INFO]   Close Engine [Demo-Synth-1]
2011-09-23 10:51:16:254240 [INFO]   Terminate Task [Demo Synth Engine]
2011-09-23 10:51:16:254416 [INFO]   Close Engine [PocketSphinx-1]
2011-09-23 10:51:16:254434 [INFO]   Terminate Task [SIP-Agent-1]
2011-09-23 10:51:16:254754 [INFO]   Receive SIP Event [nua_r_shutdown] Status 200 Shutdown successful
2011-09-23 10:51:16:255067 [INFO]   Terminate Task [RTSP-Agent-1]
2011-09-23 10:51:16:255262 [INFO]   Terminate Task [MRCPv2-Agent-1]
2011-09-23 10:51:16:255445 [INFO]   Terminate Task [Media-Engine-1]
2011-09-23 10:51:16:259495 [NOTICE] MRCP Server Terminated
2011-09-23 10:51:16:259652 [NOTICE] Server Uptime [2036 sec]
2011-09-23 10:51:16:259670 [INFO]   Destroy MRCP Engines
2011-09-23 10:51:16:259685 [INFO]   Destroy Task [Demo Synth Engine]
2011-09-23 10:51:16:259706 [INFO]   Unload Plugins
2011-09-23 10:51:16:259863 [INFO]   Destroy Task [SIP-Agent-1]
2011-09-23 10:51:16:259876 [INFO]   Destroy Task [RTSP-Agent-1]
2011-09-23 10:51:16:259941 [INFO]   Destroy Task [MRCPv2-Agent-1]
2011-09-23 10:51:16:259972 [INFO]   Destroy Task [Media-Engine-1]
2011-09-23 10:51:16:259986 [INFO]   Destroy Task [MRCP Server]

and this is asterisk log:

[Sep 23 11:48:24] VERBOSE[3254] netsock.c:   == Using SIP RTP TOS bits 184
[Sep 23 11:48:24] VERBOSE[3254] netsock.c:   == Using SIP RTP CoS mark 5
[Sep 23 11:48:24] VERBOSE[3299] pbx.c:     -- Executing [4321@from-internal:1] Answer("SIP/4001-00000001", "") in new stack
[Sep 23 11:48:25] VERBOSE[3299] pbx.c:     -- Executing [4321@from-internal:2] SpeechCreate("SIP/4001-00000001", "") in new stack
[Sep 23 11:48:25] NOTICE[3299] app_unimrcp.c: Create MRCP Handle 0x8edf048 [uni2]
[Sep 23 11:48:25] DEBUG[3299] app_unimrcp.c: Create Channel 0x8edf048 <new>
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Send session request type:2
[Sep 23 11:48:25] DEBUG[3299] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Wait for session response
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Receive App Request 0x8edf048 <new> [2]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Add MRCP Handle 0x8edf048 <new>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Dispatch App Request 0x8edf048 <new> [2]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:25] NOTICE[3272] app_unimrcp.c: Add Control Channel 0x8edf048 <new@speechrecog>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Add Media Termination 0x8edf048 <new@media-tm>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Add Media Termination 0x8edf048 <new@rtp-tm>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Signal Message to [Media-Engine-1] [1;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Signal Message to [MRCP Client] [2;0]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [2;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Control Channel Added 0x8edf048 <new@speechrecog>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3276] app_unimrcp.c: Process Message [Media-Engine-1] [1;0]
[Sep 23 11:48:25] DEBUG[3276] app_unimrcp.c: Add Media Context 0x8edf048
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [3;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Media Termination Added 0x8edf048 <new@media-tm>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Media Termination Added 0x8edf048 <new@rtp-tm>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Send Offer 0x8edf048 <new> [c:1 a:1 v:0] to 127.0.0.1:8060
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Local SDP 0x8edf048 <new>
v=0^M
c=IN IP4 127.0.0.1^M
t=0 0^M
m=application 9 TCP/MRCPv2 1^M
a=setup:active^M
a=connection:new^M
a=resource:speechrecog^M
a=cmid:1^M
m=audio 4002 RTP/AVP 0 8 96 101^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:8 PCMA/8000^M
a=rtpmap:96 L16/8000^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-15^M
a=sendonly^M
a=ptime:20^M
a=mid:1^M

[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3273] app_unimrcp.c: Receive SIP Event [nua_i_state] Status 0 INVITE sent
[Sep 23 11:48:25] NOTICE[3273] app_unimrcp.c: SIP Call State 0x8edf048 [calling]
[Sep 23 11:48:25] DEBUG[3273] app_unimrcp.c: Receive SIP Event [nua_r_invite] Status 200 OK
[Sep 23 11:48:25] DEBUG[3273] app_unimrcp.c: Receive SIP Event [nua_i_state] Status 200 OK
[Sep 23 11:48:25] NOTICE[3273] app_unimrcp.c: SIP Call State 0x8edf048 [ready]
[Sep 23 11:48:25] DEBUG[3273] app_unimrcp.c: Remote SDP 0x8edf048 <new>
v=0^M
o=UniMRCPServer 3069930143120673766 390112542560944466 IN IP4 10.4.10.171^M
s=-^M
c=IN IP4 127.0.0.1^M
t=0 0^M
m=application 1544 TCP/MRCPv2 1^M
a=setup:passive^M
a=connection:new^M
a=channel:caa5f04ad1bf405b@speechrecog^M
a=cmid:1^M
m=audio 5002 RTP/AVP 0 101^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-15^M
a=recvonly^M
a=ptime:20^M
a=mid:1^M

[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [1;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Receive Answer 0x8edf048 <new> [c:1 a:1 v:0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Modify Control Channel 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Modify Media Termination 0x8edf048 <caa5f04ad1bf405b@rtp-tm>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Signal Message to [Media-Engine-1] [1;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:25] NOTICE[3275] app_unimrcp.c: Established TCP/MRCPv2 Connection 127.0.0.1:53792 <-> 127.0.0.1:154
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Add Control Channel <caa5f04ad1bf405b@speechrecog> 127.0.0.1:53792 <-> 127.0.0.1:1544 [1]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Signal Message to [MRCP Client] [2;1]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [2;1]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Control Channel Modified 0x8edf048 <caa5f04ad1bf405b@speechrecog>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3273] app_unimrcp.c: Receive SIP Event [nua_i_active] Status 200 Call active
[Sep 23 11:48:25] DEBUG[3276] app_unimrcp.c: Process Message [Media-Engine-1] [1;0]
[Sep 23 11:48:25] DEBUG[3276] app_unimrcp.c: Enable RTP Session 127.0.0.1:4002
[Sep 23 11:48:25] DEBUG[3276] app_unimrcp.c: Create Linear Audio Bridge 0x8edf048
[Sep 23 11:48:25] DEBUG[3276] app_unimrcp.c: Open RTP Transmitter 127.0.0.1:4002 -> 127.0.0.1:5002
[Sep 23 11:48:25] DEBUG[3276] app_unimrcp.c: Media Path 0x8edf048 Source->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Encoder->[PCMU/8000/1]->Sink
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [3;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Media Termination Modified 0x8edf048 <caa5f04ad1bf405b@rtp-tm>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Raise App Response 0x8edf048 <caa5f04ad1bf405b> [2] SUCCESS [0]
[Sep 23 11:48:25] DEBUG[3272] res_speech_unimrcp.c: Received message from client stack
[Sep 23 11:48:25] DEBUG[3272] res_speech_unimrcp.c: On channel add
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Waked up, status code: 0
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Create media buffer frame_size:160
[Sep 23 11:48:25] NOTICE[3299] res_speech_unimrcp.c: Created speech instance 'caa5f04ad1bf405b'
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Set properties 'caa5f04ad1bf405b'
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Send MRCP request
[Sep 23 11:48:25] DEBUG[3299] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Wait for MRCP response
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Receive App MRCP Request 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Send MRCP Request 0x8edf048 <caa5f04ad1bf405b@speechrecog> [1]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Send MRCPv2 Stream 127.0.0.1:53792 <-> 127.0.0.1:1544 [132 bytes]
MRCP/2.0 132 SET-PARAMS 1^M
Channel-Identifier: caa5f04ad1bf405b@speechrecog^M
Recognition-Timeout: 20000^M
No-Input-Timeout: 15000^M
^M

[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:53792 <-> 127.0.0.1:1544 [80 bytes]
MRCP/2.0 80 1 200 COMPLETE^M
Channel-Identifier: caa5f04ad1bf405b@speechrecog^M
^M

[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Raise App MRCP Response 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:25] DEBUG[3272] res_speech_unimrcp.c: Received message from client stack
[Sep 23 11:48:25] DEBUG[3272] res_speech_unimrcp.c: On message receive
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Waked up
[Sep 23 11:48:25] VERBOSE[3299] pbx.c:     -- Executing [4321@from-internal:3] SpeechLoadGrammar("SIP/4001-00000001", "digit,/usr/local/unimrcp/data/grammar.jsgf") in new stack
[Sep 23 11:48:25] NOTICE[3299] res_speech_unimrcp.c: Load grammar name:digit type:application/x-jsgf path:/usr/local/unimrcp/data/grammar.jsgf 'caa5f04ad1bf405b'
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Send MRCP request
[Sep 23 11:48:25] DEBUG[3299] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 23 11:48:25] DEBUG[3299] res_speech_unimrcp.c: Wait for MRCP response
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Receive App MRCP Request 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Send MRCP Request 0x8edf048 <caa5f04ad1bf405b@speechrecog> [2]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:25] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Send MRCPv2 Stream 127.0.0.1:53792 <-> 127.0.0.1:1544 [216 bytes]
MRCP/2.0 216 DEFINE-GRAMMAR 2^M
Channel-Identifier: caa5f04ad1bf405b@speechrecog^M
Content-Type: application/x-jsgf^M
Content-Id: digit^M
Content-Length: 60^M
^M
#JSGF V1.0;
grammar digits;
public <numbers> = (one | two);

[Sep 23 11:48:25] DEBUG[3275] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:53792 <-> 127.0.0.1:1544 [112 bytes]
MRCP/2.0 112 2 407 COMPLETE^M
Channel-Identifier: caa5f04ad1bf405b@speechrecog^M
Completion-Cause: 000 success^M
^M

[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Raise App MRCP Response 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:34] DEBUG[3272] res_speech_unimrcp.c: Received message from client stack
[Sep 23 11:48:34] DEBUG[3272] res_speech_unimrcp.c: On message receive
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:34] DEBUG[3299] res_speech_unimrcp.c: Waked up
[Sep 23 11:48:34] WARNING[3299] res_speech_unimrcp.c: Received failure response
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:   == Spawn extension (from-internal, 4321, 3) exited non-zero on 'SIP/4001-00000001'
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [h@from-internal:1] Macro("SIP/4001-00000001", "hangupcall") in new stack
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [s@macro-hangupcall:1] GotoIf("SIP/4001-00000001", "1?noautomon") in new stack
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Goto (macro-hangupcall,s,3)
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [s@macro-hangupcall:3] NoOp("SIP/4001-00000001", "TOUCH_MONITOR_OUTPUT=") in new stack
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [s@macro-hangupcall:4] GotoIf("SIP/4001-00000001", "1?noautomon2") in new stack
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Goto (macro-hangupcall,s,6)
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [s@macro-hangupcall:6] NoOp("SIP/4001-00000001", "MONITOR_FILENAME=") in new stack
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [s@macro-hangupcall:7] GotoIf("SIP/4001-00000001", "1?skiprg") in new stack
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Goto (macro-hangupcall,s,10)
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [s@macro-hangupcall:10] GotoIf("SIP/4001-00000001", "1?skipblkvm") in new stack
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Goto (macro-hangupcall,s,13)
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [s@macro-hangupcall:13] GotoIf("SIP/4001-00000001", "1?theend") in new stack
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Goto (macro-hangupcall,s,15)
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:     -- Executing [s@macro-hangupcall:15] Hangup("SIP/4001-00000001", "") in new stack
[Sep 23 11:48:34] VERBOSE[3299] app_macro.c:   == Spawn extension (macro-hangupcall, s, 15) exited non-zero on 'SIP/4001-00000001' in macro 'hangupcall'
[Sep 23 11:48:34] VERBOSE[3299] pbx.c:   == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/4001-00000001'
[Sep 23 11:48:34] NOTICE[3299] res_speech_unimrcp.c: Destroy speech instance 'caa5f04ad1bf405b'
[Sep 23 11:48:34] DEBUG[3299] res_speech_unimrcp.c: Send session request type:1
[Sep 23 11:48:34] DEBUG[3299] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Receive App Request 0x8edf048 <caa5f04ad1bf405b> [1]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Dispatch App Request 0x8edf048 <caa5f04ad1bf405b> [1]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Terminate Session 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Remove Control Channel 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Subtract Media Termination 0x8edf048 <caa5f04ad1bf405b@media-tm>
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Subtract Media Termination 0x8edf048 <caa5f04ad1bf405b@rtp-tm>
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Signal Message to [Media-Engine-1] [1;0]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Remove Control Channel <caa5f04ad1bf405b@speechrecog> [0]
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Close TCP/MRCPv2 Connection 127.0.0.1:53792 <-> 127.0.0.1:1544
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Signal Message to [MRCP Client] [2;2]
[Sep 23 11:48:34] DEBUG[3275] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [2;2]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Control Channel Removed 0x8edf048 <caa5f04ad1bf405b@speechrecog>
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:34] DEBUG[3273] app_unimrcp.c: Receive SIP Event [nua_r_bye] Status 200 OK
[Sep 23 11:48:34] DEBUG[3273] app_unimrcp.c: Receive SIP Event [nua_i_state] Status 200 to BYE
[Sep 23 11:48:34] NOTICE[3273] app_unimrcp.c: SIP Call State 0x8edf048 [terminated]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [1;1]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Session Terminated 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:34] DEBUG[3299] res_speech_unimrcp.c: Wait for session response
[Sep 23 11:48:34] DEBUG[3276] app_unimrcp.c: Process Message [Media-Engine-1] [1;0]
[Sep 23 11:48:34] DEBUG[3276] app_unimrcp.c: Destroy Audio Bridge 0x8edf048
[Sep 23 11:48:34] DEBUG[3276] app_unimrcp.c: Close RTP Transmitter 127.0.0.1:4002 -> 127.0.0.1:5002 [s:0 o:0]
[Sep 23 11:48:34] DEBUG[3276] app_unimrcp.c: Remove Media Context 0x8edf048
[Sep 23 11:48:34] DEBUG[3276] app_unimrcp.c: Remove RTP Session 127.0.0.1:4002
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Process Message [MRCP Client] [3;0]
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Media Termination Subtracted 0x8edf048 <caa5f04ad1bf405b@media-tm>
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Media Termination Subtracted 0x8edf048 <caa5f04ad1bf405b@rtp-tm>
[Sep 23 11:48:34] NOTICE[3272] app_unimrcp.c: Destroy TCP/MRCPv2 Connection 127.0.0.1:53792 <-> 127.0.0.1:1544
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Remove MRCP Handle 0x8edf048 <caa5f04ad1bf405b>
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Raise App Response 0x8edf048 <caa5f04ad1bf405b> [1] SUCCESS [0]
[Sep 23 11:48:34] DEBUG[3272] res_speech_unimrcp.c: Received message from client stack
[Sep 23 11:48:34] DEBUG[3272] res_speech_unimrcp.c: On session terminate
[Sep 23 11:48:34] DEBUG[3272] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 23 11:48:34] DEBUG[3299] res_speech_unimrcp.c: Waked up, status code: 0
[Sep 23 11:48:34] NOTICE[3299] app_unimrcp.c: Destroy MRCP Handle 0x8edf048

I noticed de WARN message from unimrcp server log, looked up on the web i
found this:http://groups.google.com/group/unimrcp/browse_thread/thread/bb54ed
5ff1f2e9f , but that didin't solved my problem.

Am i missing a configuration step? is it because of asterisk, unimrcp,
pocketsphinx or an silly mistake that i made the reason of this error?. Please
need some guidelines. Really need and want to get this working togheter

Nickolay V. Shmyrev - 2011-09-26

Read the log

INFO: dict.c(321): Reading main dictionary: ../data/default.dic ERROR: "fsg_search.c", line 332: The word 'two' is missing in the dictionary

Open the file ../data/default.dic and add the word 'two' there. Get the
transcription from the file

pocketsphinx/model/lm/en_US/cmu07a.dic
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Anonymous - 2011-09-26

I checked that, and i remember to look for the word "two" and was in there.
Actually, the default grammar.jsgf had the word "three" too, and the error
said:

ERROR: "fsg_search.c", line 332: The word 'three' is missing in the dictionary

exactly the same, i tried with tidigits model and "tidigits.dic" too and
nothing, the same mistake; also tried with pockesphinx0.6.1 and
sphinxbase0.6.1 and had the same problem. At this moment i'm formatting my pc
and i'll try again with a fresh new install because i really don't understand
what has happened.

Thank's for you reply.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Nickolay V. Shmyrev - 2011-09-27

I checked that, and i remember to look for the word "two" and was in there.
Actually, the default grammar.jsgf had the word "three" too, and the error
said:

Most likely you edited wrong dictionary. The dictionary is located in data
folder and it's name is default.dic. You can share this file if you don't see
yourself what is wrong there.

At this moment i'm formatting my pc and i'll try again with a fresh new
install because i really don't understand what has happened.

That's not the right thing to do. It's like you will buy a new one if previous
doens't work

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Hi again nsh. The file i edited was in the data folder, but, after i
downloaded all the files again, i installed unimrcp 1.0.0 again with
pocketsphinx and sphinxbase both 0.7 version, the rare thing was that neither
the default.dic and the wsj1 default model were on the data/ folder. So i ran
copied the dictionary that you suggested and create a test dictionary.

These are my configuration files:

unimrpclient-config-snapshot

 <properties>
    <!-- By default, network interface (IP address) to bind to will be implicitly identified.
         Alternatively, it can be explicitly set.
    -->
    <ip type="auto"/>
    <!-- <ip>10.10.0.1</ip> -->
    <!-- <ext-ip>a.b.c.d</ext-ip> -->
    <!-- <server-ip>a.b.c.d</server-ip> -->
  </properties>







pocketsphinx.xml

<?xml version="1.0" encoding="UTF-8"?>
<!-- PocketSphinx Document -->
<pocketsphinx>

  <sensitivity level="50" timeout="300"/>

  <timers noinput-timeout="10000" recognition-timeout="15000"/>

  <model dir="" narrowband="Communicator_40.cd_cont_4000" wideband="Communicator_40.cd_cont_4000" dictionary="default.dic" preferred="narrowband"/>

  <save-waveform dir="" enable="0"/>
</pocketsphinx>

res-speech-unimrcp is default.

and this is the Dialplan:

[example-pocketsphinx]
exten => 5551,1,Answer()
exten => 5551,2,SpeechCreate()
exten => 5551,3,SpeechLoadGrammar(digit,/usr/local/unimrcp/data/grammar.jsgf)
exten => 5551,4,SpeechActivateGrammar(digit)
exten => 5551,5,SpeechBackground(beep,20)
exten => 5551,6,Verbose(1,Fernando es ${SPEECH(results)} y ${SPEECH_TEXT(0)})
exten => 5551,7,GotoIf($[${SPEECH(results)} = 0]?8:10)
exten => 5551,8,Playback(vm-nonumber)
exten => 5551,9,Goto(5)
exten => 5551,10,Verbose(1,The recognized input is ${SPEECH_TEXT(0)})
exten => 5551,11,Verbose(1,The score is ${SPEECH_SCORE(0)})
exten => 5551,12,Verbose(1,The matched grammar is ${SPEECH_GRAMMAR(0)})
exten => 5551,13,SpeechDeactivateGrammar(digit)
exten => 5551,14,SpeechUnloadGrammar(digit)
exten => 5551,15,SpeechDestroy()
exten => 5551,16,Hangup()

Now the "SpeechLoadGrammar(digit,/usr/local/unimrcp/data/grammar.jsgf)"
instruction it's being passed.

This is unimrcpserver log:

2011-09-27 11:15:58:137374 [INFO]   Init Decoder <a02f9a94980c4c02@pocketsphinx>
INFO: cmd_ln.c(691): Parsing command line:
\
        -alpha 0.97 \
        -dither yes \
        -doublebw no \
        -nfilt 31 \
        -ncep 13 \
        -lowerf 200 \
        -upperf 3500 \
        -nfft 256 \
        -wlen 0.0256 \
        -transform legacy \
        -feat 1s_c_d_dd \
        -agc none \
        -cmn current \
        -varnorm no

Current configuration:
[NAME]          [DEFLT]         [VALUE]
-agc            none            none
-agcthresh      2.0             2.000000e+00
-alpha          0.97            9.700000e-01
-ceplen         13              13
-cmn            current         current
-cmninit        8.0             8.0
-dither         no              yes
-doublebw       no              no
-feat           1s_c_d_dd       1s_c_d_dd
-frate          100             50
-input_endian   little          little
-lda
-ldadim         0               0
-lifter         0               0
-logspec        no              no
-lowerf         133.33334       2.000000e+02
-ncep           13              13
-nfft           512             256
-nfilt          40              31
-remove_dc      no              no
-round_filters  yes             yes
-samprate       16000           8.000000e+03
-seed           -1              -1
-smoothspec     no              no
-svspec
-transform      legacy          legacy
-unit_area      yes             yes
-upperf         6855.4976       3.500000e+03
-varnorm        no              no
-verbose        no              no
-warp_params
-warp_type      inverse_linear  inverse_linear
-wlen           0.025625        2.560000e-02

INFO: acmod.c(242): Parsed model-specific feature parameters from ../data/Communicator_40.cd_cont_4000/feat.params
INFO: fe_interface.c(289): You are using the internal mechanism to generate the seed.
INFO: feat.c(684): Initializing feature stream to type: '1s_c_d_dd', ceplen=13, CMN='current', VARNORM='no', AGC='none'
INFO: cmn.c(142): mean[0]= 12.00, mean[1..12]= 0.0
INFO: mdef.c(520): Reading model definition: ../data/Communicator_40.cd_cont_4000/mdef
INFO: bin_mdef.c(173): Allocating 104160 * 8 bytes (813 KiB) for CD tree
INFO: tmat.c(205): Reading HMM transition probability matrices: ../data/Communicator_40.cd_cont_4000/transition_matrices
INFO: acmod.c(117): Attempting to use SCHMM computation module
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/Communicator_40.cd_cont_4000/means
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/Communicator_40.cd_cont_4000/variances
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(354): 44589 variance values floored
INFO: acmod.c(119): Attempting to use PTHMM computation module
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/Communicator_40.cd_cont_4000/means
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/Communicator_40.cd_cont_4000/variances
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(354): 44589 variance values floored
INFO: ptm_mgau.c(800): Number of codebooks exceeds 256: 4153
INFO: acmod.c(121): Falling back to general multi-stream GMM computation
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/Communicator_40.cd_cont_4000/means
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/Communicator_40.cd_cont_4000/variances
INFO: ms_gauden.c(292): 4153 codebook, 1 feature, size:
INFO: ms_gauden.c(294):  64x39
INFO: ms_gauden.c(354): 44589 variance values floored
INFO: ms_senone.c(160): Reading senone mixture weights: ../data/Communicator_40.cd_cont_4000/mixture_weights
INFO: ms_senone.c(211): Truncating senone logs3(pdf) values by 10 bits
INFO: ms_senone.c(218): Not transposing mixture weights in memory
INFO: ms_senone.c(277): Read mixture weights for 4153 senones: 1 features x 64 codewords
INFO: ms_senone.c(331): Mapping senones to individual codebooks
INFO: ms_mgau.c(122): The value of topn: 4
INFO: dict.c(306): Allocating 137534 * 20 bytes (2686 KiB) for word entries
INFO: dict.c(321): Reading main dictionary: ../data/default.dic
INFO: dict.c(212): Allocated 1010 KiB for strings, 1664 KiB for phones
INFO: dict.c(324): 133436 words read
INFO: dict.c(330): Reading filler dictionary: ../data/Communicator_40.cd_cont_4000/noisedict
INFO: dict.c(212): Allocated 0 KiB for strings, 0 KiB for phones
INFO: dict.c(333): 3 words read
INFO: dict2pid.c(396): Building PID tables for dictionary
INFO: dict2pid.c(404): Allocating 51^3 * 2 bytes (259 KiB) for word-initial triphones
INFO: dict2pid.c(131): Allocated 31416 bytes (30 KiB) for word-final triphones
INFO: dict2pid.c(195): Allocated 31416 bytes (30 KiB) for single-phone word triphones
INFO: fsg_search.c(145): FSG(beam: -1080, pbeam: -1080, wbeam: -634; wip: -26, pip: 0)
INFO: jsgf.c(546): Defined rule: <digits.g00000>
INFO: jsgf.c(546): Defined rule: PUBLIC <digits.numbers>
INFO: fsg_model.c(213): Computing transitive closure for null transitions
INFO: fsg_model.c(264): 3 null transitions added
INFO: fsg_model.c(411): Adding silence transitions for <sil> to FSG
INFO: fsg_model.c(431): Added 7 silence word transitions
INFO: fsg_search.c(364): Added 1 alternate word transitions
INFO: fsg_lextree.c(108): Allocated 728 bytes (0 KiB) for left and right context phones
INFO: fsg_lextree.c(251): 19 HMM nodes in lextree (11 leaves)
INFO: fsg_lextree.c(253): Allocated 2052 bytes (2 KiB) for all lextree nodes
INFO: fsg_lextree.c(256): Allocated 1188 bytes (1 KiB) for lextree leafnodes
2011-09-27 11:16:06:852928 [INFO]   Process DEFINE-GRAMMAR Response <a02f9a94980c4c02@speechrecog> [2]
2011-09-27 11:16:06:853063 [INFO]   Send MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:41900 [112 bytes]
MRCP/2.0 112 2 200 COMPLETE
Channel-Identifier: a02f9a94980c4c02@speechrecog
Completion-Cause: 000 success


2011-09-27 11:16:06:857212 [INFO]   Receive MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:41900 [190 bytes]
MRCP/2.0 190 RECOGNIZE 3
Channel-Identifier: a02f9a94980c4c02@speechrecog
Content-Type: text/uri-list
Cancel-If-Queue: false
Start-Input-Timers: true
Content-Length: 13

session:digit
2011-09-27 11:16:06:857499 [INFO]   Process RECOGNIZE Request <a02f9a94980c4c02@speechrecog> [3]
2011-09-27 11:16:06:857780 [INFO]   Dispatch Request RECOGNIZE <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:06:858029 [INFO]   Process RECOGNIZE Response <a02f9a94980c4c02@speechrecog> [3]
2011-09-27 11:16:06:858145 [INFO]   State Transition IDLE -> RECOGNIZING <a02f9a94980c4c02@speechrecog>
2011-09-27 11:16:06:858269 [INFO]   Send MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:41900 [83 bytes]
MRCP/2.0 83 3 200 IN-PROGRESS
Channel-Identifier: a02f9a94980c4c02@speechrecog


2011-09-27 11:16:07:420133 [INFO]   Detected Voice Activity <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:07:420375 [INFO]   Process START-OF-INPUT Event <a02f9a94980c4c02@speechrecog> [3]
2011-09-27 11:16:07:420587 [INFO]   Send MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:41900 [94 bytes]
MRCP/2.0 94 START-OF-INPUT 3 IN-PROGRESS
Channel-Identifier: a02f9a94980c4c02@speechrecog


2011-09-27 11:16:09:560354 [INFO]   Get Recognition Partial Result [three] Score [-2787] <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:26:859621 [INFO]   Recognition Timeout Elapsed <a02f9a94980c4c02@pocketsphinx>
INFO: cmn_prior.c(121): cmn_prior_update: from <  9.23 -0.49 -0.05 -0.10 -0.24 -0.18 -0.17 -0.16 -0.15 -0.10 -0.10 -0.15 -0.08 >
INFO: cmn_prior.c(139): cmn_prior_update: to   <  8.83 -0.52 -0.07 -0.08 -0.23 -0.17 -0.15 -0.16 -0.15 -0.08 -0.10 -0.14 -0.06 >
INFO: fsg_search.c(1030): 1000 frames, 14661 HMMs (14/fr), 36540 senones (36/fr), 7615 history entries (7/fr)

INFO: fsg_search.c(1407): Start node <sil>.0:2:821
INFO: fsg_search.c(1446): End node <sil>.951:966:999 (-489)
INFO: fsg_search.c(1662): lattice start node <sil>.0 end node <sil>.951
INFO: ps_lattice.c(1352): Normalizer P(O) = alpha(<sil>:951:999) = -536870912
WARNING: "fsg_search.c", line 1155: Failed to bestpath in a lattice
2011-09-27 11:16:26:887854 [INFO]   Process RECOGNITION-COMPLETE Event <a02f9a94980c4c02@speechrecog> [3]
2011-09-27 11:16:26:887881 [INFO]   State Transition RECOGNIZING -> RECOGNIZED <a02f9a94980c4c02@speechrecog>
2011-09-27 11:16:26:887991 [INFO]   Send MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:41900 [137 bytes]
MRCP/2.0 137 RECOGNITION-COMPLETE 3 COMPLETE
Channel-Identifier: a02f9a94980c4c02@speechrecog
Completion-Cause: 003 hotword-maxtime


2011-09-27 11:16:29:505247 [INFO]   Receive MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:41900 [190 bytes]
MRCP/2.0 190 RECOGNIZE 4
Channel-Identifier: a02f9a94980c4c02@speechrecog
Content-Type: text/uri-list
Cancel-If-Queue: false
Start-Input-Timers: true
Content-Length: 13

session:digit
2011-09-27 11:16:29:505534 [INFO]   Process RECOGNIZE Request <a02f9a94980c4c02@speechrecog> [4]
2011-09-27 11:16:29:505657 [INFO]   Dispatch Request RECOGNIZE <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:29:507404 [INFO]   Process RECOGNIZE Response <a02f9a94980c4c02@speechrecog> [4]
2011-09-27 11:16:29:507440 [INFO]   State Transition RECOGNIZED -> RECOGNIZING <a02f9a94980c4c02@speechrecog>
2011-09-27 11:16:29:507660 [INFO]   Send MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:41900 [83 bytes]
MRCP/2.0 83 4 200 IN-PROGRESS
Channel-Identifier: a02f9a94980c4c02@speechrecog


2011-09-27 11:16:29:809701 [INFO]   Get Recognition Partial Result [two] Score [-714] <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:29:889679 [INFO]   Detected Voice Activity <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:29:889878 [INFO]   Process START-OF-INPUT Event <a02f9a94980c4c02@speechrecog> [4]
2011-09-27 11:16:29:890020 [INFO]   Send MRCPv2 Stream 127.0.0.1:1544 <-> 127.0.0.1:41900 [94 bytes]
MRCP/2.0 94 START-OF-INPUT 4 IN-PROGRESS
Channel-Identifier: a02f9a94980c4c02@speechrecog


2011-09-27 11:16:33:009766 [INFO]   Get Recognition Partial Result [one] Score [-3327] <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:33:109768 [INFO]   Get Recognition Partial Result [two] Score [-3524] <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:33:205751 [INFO]   Receive SIP Event [nua_i_bye] Status 200 Session Terminated
2011-09-27 11:16:33:205794 [INFO]   Receive SIP Event [nua_i_state] Status 200 Session Terminated
2011-09-27 11:16:33:205808 [NOTICE] SIP Call State 0x858a0c0 [terminated]
2011-09-27 11:16:33:205832 [INFO]   Receive SIP Event [nua_i_terminated] Status 200 Session Terminated
2011-09-27 11:16:33:206786 [INFO]   Deactivate Session 0x858a0c0 <a02f9a94980c4c02>
2011-09-27 11:16:33:206956 [INFO]   Create and Process STOP Request <a02f9a94980c4c02@speechrecog> [5]
2011-09-27 11:16:33:207050 [INFO]   Dispatch Request DEACTIVATE <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:33:207226 [INFO]   TCP/MRCPv2 Peer Disconnected 127.0.0.1:1544 <-> 127.0.0.1:41900
INFO: cmn_prior.c(121): cmn_prior_update: from <  8.70 -0.52 -0.04 -0.07 -0.23 -0.17 -0.15 -0.16 -0.15 -0.09 -0.11 -0.14 -0.07 >
INFO: cmn_prior.c(139): cmn_prior_update: to   <  8.69 -0.51 -0.03 -0.06 -0.23 -0.17 -0.15 -0.16 -0.15 -0.09 -0.11 -0.14 -0.07 >
INFO: fsg_search.c(1030): 185 frames, 2996 HMMs (16/fr), 6939 senones (37/fr), 2113 history entries (11/fr)

2011-09-27 11:16:33:238970 [INFO]   Process DEACTIVATE Response <a02f9a94980c4c02@speechrecog> [5]
2011-09-27 11:16:33:239175 [INFO]   State Transition RECOGNIZING -> IDLE <a02f9a94980c4c02@speechrecog>
2011-09-27 11:16:33:239250 [INFO]   Terminate Session 0x858a0c0 <a02f9a94980c4c02>
2011-09-27 11:16:33:239360 [INFO]   Close Channel <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:33:239453 [INFO]   Remove Grammar File [../data/a02f9a94980c4c02-digit.gram] <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:33:239632 [INFO]   Free Decoder <a02f9a94980c4c02@pocketsphinx>
2011-09-27 11:16:33:251564 [NOTICE] Remove Session <a02f9a94980c4c02>
2011-09-27 11:16:33:251990 [INFO]   Remove Control Channel <a02f9a94980c4c02@speechrecog> [0]
2011-09-27 11:16:33:258765 [INFO]   Close RTP Receiver 127.0.0.1:5000 <- 127.0.0.1:4004 [r:1192 l:0 j:47 d:0 i:0]
2011-09-27 11:16:33:258791 [INFO]   Remove RTP Session 127.0.0.1:5000
2011-09-27 11:16:33:258924 [NOTICE] Destroy TCP/MRCPv2 Connection 127.0.0.1:1544 <-> 127.0.0.1:41900
2011-09-27 11:16:33:259023 [INFO]   Session Terminated 0x858a0c0 <a02f9a94980c4c02>
2011-09-27 11:16:33:259194 [NOTICE] Destroy Session <a02f9a94980c4c02>

This is asterisk log:

[Sep 27 11:15:57] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:1] Answer("SIP/4001-00000006", "") in new stack
[Sep 27 11:15:58] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:2] SpeechCreate("SIP/4001-00000006", "") in new stack
[Sep 27 11:15:58] NOTICE[3379] app_unimrcp.c: Create MRCP Handle 0xa5236d0 [uni2]
[Sep 27 11:15:58] DEBUG[3379] app_unimrcp.c: Create Channel 0xa5236d0 <new>
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Send session request type:2
[Sep 27 11:15:58] DEBUG[3379] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Wait for session response
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Receive App Request 0xa5236d0 <new> [2]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Add MRCP Handle 0xa5236d0 <new>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Dispatch App Request 0xa5236d0 <new> [2]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 27 11:15:58] NOTICE[3199] app_unimrcp.c: Add Control Channel 0xa5236d0 <new@speechrecog>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Add Media Termination 0xa5236d0 <new@media-tm>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Add Media Termination 0xa5236d0 <new@rtp-tm>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Signal Message to [Media-Engine-1] [1;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;0]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Control Channel Added 0xa5236d0 <new@speechrecog>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3203] app_unimrcp.c: Process Message [Media-Engine-1] [1;0]
[Sep 27 11:15:58] DEBUG[3203] app_unimrcp.c: Add Media Context 0xa5236d0
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [3;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Media Termination Added 0xa5236d0 <new@media-tm>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Media Termination Added 0xa5236d0 <new@rtp-tm>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Send Offer 0xa5236d0 <new> [c:1 a:1 v:0] to 127.0.0.1:8060
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Local SDP 0xa5236d0 <new>
v=0^M
o=UniMRCPClient 0 0 IN IP4 127.0.0.1^M
s=-^M
c=IN IP4 127.0.0.1^M
t=0 0^M
m=application 9 TCP/MRCPv2 1^M
a=setup:active^M
a=connection:new^M
a=resource:speechrecog^M
a=cmid:1^M
m=audio 4004 RTP/AVP 0 8 96 101^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:8 PCMA/8000^M
a=rtpmap:96 L16/8000^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-15^M
a=sendonly^M
a=ptime:20^M
a=mid:1^M

[Sep 27 11:15:58] DEBUG[3200] app_unimrcp.c: Receive SIP Event [nua_i_state] Status 0 INVITE sent
[Sep 27 11:15:58] NOTICE[3200] app_unimrcp.c: SIP Call State 0xa5236d0 [calling]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3200] app_unimrcp.c: Receive SIP Event [nua_r_invite] Status 200 OK
[Sep 27 11:15:58] DEBUG[3200] app_unimrcp.c: Receive SIP Event [nua_i_state] Status 200 OK
[Sep 27 11:15:58] NOTICE[3200] app_unimrcp.c: SIP Call State 0xa5236d0 [ready]
[Sep 27 11:15:58] DEBUG[3200] app_unimrcp.c: Remote SDP 0xa5236d0 <new>
v=0^M
o=UniMRCPServer 932435341252017986 6236807942614359170 IN IP4 10.4.10.171^M
s=-^M
c=IN IP4 127.0.0.1^M
t=0 0^M
m=application 1544 TCP/MRCPv2 1^M
a=setup:passive^M
a=connection:new^M
a=channel:a02f9a94980c4c02@speechrecog^M
a=cmid:1^M
m=audio 5000 RTP/AVP 0 101^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-15^M
a=recvonly^M
a=ptime:20^M
a=mid:1^M
[Sep 27 11:15:58] DEBUG[3200] app_unimrcp.c: Receive SIP Event [nua_i_active] Status 200 Call active
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [1;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Receive Answer 0xa5236d0 <new> [c:1 a:1 v:0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Modify Control Channel 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Modify Media Termination 0xa5236d0 <a02f9a94980c4c02@rtp-tm>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Signal Message to [Media-Engine-1] [1;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 27 11:15:58] NOTICE[3202] app_unimrcp.c: Established TCP/MRCPv2 Connection 127.0.0.1:41900 <-> 127.0.0.1:1544
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Add Control Channel <a02f9a94980c4c02@speechrecog> 127.0.0.1:41900 <-> 127.0.0.1:1544 [1]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;1]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;1]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Control Channel Modified 0xa5236d0 <a02f9a94980c4c02@speechrecog>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3203] app_unimrcp.c: Process Message [Media-Engine-1] [1;0]
[Sep 27 11:15:58] DEBUG[3203] app_unimrcp.c: Enable RTP Session 127.0.0.1:4004
[Sep 27 11:15:58] DEBUG[3203] app_unimrcp.c: Create Linear Audio Bridge 0xa5236d0
[Sep 27 11:15:58] DEBUG[3203] app_unimrcp.c: Open RTP Transmitter 127.0.0.1:4004 -> 127.0.0.1:5000
[Sep 27 11:15:58] DEBUG[3203] app_unimrcp.c: Media Path 0xa5236d0 Source->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Encoder->[PCMU/8000/1]->Sink
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [3;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Media Termination Modified 0xa5236d0 <a02f9a94980c4c02@rtp-tm>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Raise App Response 0xa5236d0 <a02f9a94980c4c02> [2] SUCCESS [0]
[Sep 27 11:15:58] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:15:58] DEBUG[3199] res_speech_unimrcp.c: On channel add
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Waked up, status code: 0
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Create media buffer frame_size:160
[Sep 27 11:15:58] NOTICE[3379] res_speech_unimrcp.c: Created speech instance 'a02f9a94980c4c02'
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Set properties 'a02f9a94980c4c02'
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Send MRCP request
[Sep 27 11:15:58] DEBUG[3379] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Wait for MRCP response
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Receive App MRCP Request 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Send MRCP Request 0xa5236d0 <a02f9a94980c4c02@speechrecog> [1]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Send MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [132 bytes]
MRCP/2.0 132 SET-PARAMS 1^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
Recognition-Timeout: 20000^M
No-Input-Timeout: 15000^M
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [80 bytes]
MRCP/2.0 80 1 200 COMPLETE^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
^M

[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Raise App MRCP Response 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:15:58] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:15:58] DEBUG[3199] res_speech_unimrcp.c: On message receive
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Waked up
[Sep 27 11:15:58] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:3] SpeechLoadGrammar("SIP/4001-00000006", "digit,/usr/local/unimrcp/data/grammar.jsgf") in new stack
[Sep 27 11:15:58] NOTICE[3379] res_speech_unimrcp.c: Load grammar name:digit type:application/x-jsgf path:/usr/local/unimrcp/data/grammar.jsgf 'a02f9a94980c4c02'
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Send MRCP request
[Sep 27 11:15:58] DEBUG[3379] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 27 11:15:58] DEBUG[3379] res_speech_unimrcp.c: Wait for MRCP response
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Receive App MRCP Request 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Send MRCP Request 0xa5236d0 <a02f9a94980c4c02@speechrecog> [2]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 27 11:15:58] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Send MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [227 bytes]
MRCP/2.0 227 DEFINE-GRAMMAR 2^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
Content-Type: application/x-jsgf^M
Content-Id: digit^M
Content-Length: 71^M
^M
#JSGF V1.0;^M
grammar digits;^M
public <numbers> = (one | two | three);^M

[Sep 27 11:15:58] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [112 bytes]
MRCP/2.0 112 2 200 COMPLETE^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
Completion-Cause: 000 success^M
^M

[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Raise App MRCP Response 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:06] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:16:06] DEBUG[3199] res_speech_unimrcp.c: On message receive
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Waked up
[Sep 27 11:16:06] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:4] SpeechActivateGrammar("SIP/4001-00000006", "digit") in new stack
[Sep 27 11:16:06] NOTICE[3379] res_speech_unimrcp.c: Activate grammar name:digit 'a02f9a94980c4c02'
[Sep 27 11:16:06] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:5] SpeechBackground("SIP/4001-00000006", "beep,20") in new stack
[Sep 27 11:16:06] NOTICE[3379] res_speech_unimrcp.c: Start audio 'a02f9a94980c4c02'
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Send MRCP request
[Sep 27 11:16:06] DEBUG[3379] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Wait for MRCP response
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Receive App MRCP Request 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Send MRCP Request 0xa5236d0 <a02f9a94980c4c02@speechrecog> [3]
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Send MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [190 bytes]
MRCP/2.0 190 RECOGNIZE 3^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
Content-Type: text/uri-list^M
Cancel-If-Queue: false^M
Start-Input-Timers: true^M
Content-Length: 13^M
^M
session:digit
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [83 bytes]
MRCP/2.0 83 3 200 IN-PROGRESS^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
^M

[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 27 11:16:06] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Raise App MRCP Response 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:06] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:16:06] DEBUG[3199] res_speech_unimrcp.c: On message receive
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Waked up
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:06] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:07] DEBUG[3379] res_speech_unimrcp.c: Failed to write audio len:320
[Sep 27 11:16:07] DEBUG[3202] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 27 11:16:07] DEBUG[3202] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [94 bytes]
MRCP/2.0 94 START-OF-INPUT 3 IN-PROGRESS^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
^M

[Sep 27 11:16:07] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 27 11:16:07] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:07] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 27 11:16:07] DEBUG[3199] app_unimrcp.c: Raise App MRCP Event 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:07] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:16:07] DEBUG[3199] res_speech_unimrcp.c: On message receive
[Sep 27 11:16:07] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:26] DEBUG[3202] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 27 11:16:26] DEBUG[3202] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [137 bytes]
MRCP/2.0 137 RECOGNITION-COMPLETE 3 COMPLETE^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
Completion-Cause: 003 hotword-maxtime^M
^M

[Sep 27 11:16:26] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 27 11:16:26] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:26] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 27 11:16:26] DEBUG[3199] app_unimrcp.c: Raise App MRCP Event 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:26] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:16:26] DEBUG[3199] res_speech_unimrcp.c: On message receive
[Sep 27 11:16:26] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:26] NOTICE[3379] res_speech_unimrcp.c: Get result 'a02f9a94980c4c02'
[Sep 27 11:16:26] WARNING[3379] res_speech_unimrcp.c: Unsuccessful completion cause:3 reason:none
[Sep 27 11:16:26] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:6] Verbose("SIP/4001-00000006", "1,Fernando es 0 y ") in new stack
[Sep 27 11:16:26] VERBOSE[3379] app_verbose.c:  Fernando es 0 y
[Sep 27 11:16:26] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:7] GotoIf("SIP/4001-00000006", "1?8:10") in new stack
[Sep 27 11:16:26] VERBOSE[3379] pbx.c:     -- Goto (from-internal,5551,8)
[Sep 27 11:16:26] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:8] Playback("SIP/4001-00000006", "vm-nonumber") in new stack
[Sep 27 11:16:26] VERBOSE[3379] file.c:     -- <SIP/4001-00000006> Playing 'vm-nonumber.gsm' (language 'en')
[Sep 27 11:16:29] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:9] Goto("SIP/4001-00000006", "5") in new stack
[Sep 27 11:16:29] VERBOSE[3379] pbx.c:     -- Goto (from-internal,5551,5)
[Sep 27 11:16:29] VERBOSE[3379] pbx.c:     -- Executing [5551@from-internal:5] SpeechBackground("SIP/4001-00000006", "beep,20") in new stack
[Sep 27 11:16:29] NOTICE[3379] res_speech_unimrcp.c: Start audio 'a02f9a94980c4c02'

[Sep 27 11:16:29] DEBUG[3379] res_speech_unimrcp.c: Send MRCP request
[Sep 27 11:16:29] DEBUG[3379] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 27 11:16:29] DEBUG[3379] res_speech_unimrcp.c: Wait for MRCP response
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Receive App MRCP Request 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Send MRCP Request 0xa5236d0 <a02f9a94980c4c02@speechrecog> [4]
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Send MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [190 bytes]
MRCP/2.0 190 RECOGNIZE 4^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
Content-Type: text/uri-list^M
Cancel-If-Queue: false^M
Start-Input-Timers: true^M
Content-Length: 13^M
^M
session:digit
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [83 bytes]
MRCP/2.0 83 4 200 IN-PROGRESS^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
^M

[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Raise App MRCP Response 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:29] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:16:29] DEBUG[3199] res_speech_unimrcp.c: On message receive
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:29] DEBUG[3379] res_speech_unimrcp.c: Waked up
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Process Signalled Descriptor [MRCPv2-Agent-1]
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Receive MRCPv2 Stream 127.0.0.1:41900 <-> 127.0.0.1:1544 [94 bytes]
MRCP/2.0 94 START-OF-INPUT 4 IN-PROGRESS^M
Channel-Identifier: a02f9a94980c4c02@speechrecog^M
^M

[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;3]
[Sep 27 11:16:29] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;3]
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Raise App MRCP Event 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:29] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:16:29] DEBUG[3199] res_speech_unimrcp.c: On message receive
[Sep 27 11:16:29] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:33] NOTICE[3379] res_speech_unimrcp.c: Destroy speech instance 'a02f9a94980c4c02'
[Sep 27 11:16:33] DEBUG[3379] res_speech_unimrcp.c: Send session request type:1
[Sep 27 11:16:33] DEBUG[3379] app_unimrcp.c: Signal Message to [MRCP Client] [4;0]
[Sep 27 11:16:33] DEBUG[3379] res_speech_unimrcp.c: Wait for session response
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [4;0]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Receive App Request 0xa5236d0 <a02f9a94980c4c02> [1]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Dispatch App Request 0xa5236d0 <a02f9a94980c4c02> [1]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Terminate Session 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Remove Control Channel 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Signal Message to [MRCPv2-Agent-1] [1;0]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Subtract Media Termination 0xa5236d0 <a02f9a94980c4c02@media-tm>
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Subtract Media Termination 0xa5236d0 <a02f9a94980c4c02@rtp-tm>
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Signal Message to [Media-Engine-1] [1;0]
[Sep 27 11:16:33] DEBUG[3200] app_unimrcp.c: Receive SIP Event [nua_r_bye] Status 200 OK
[Sep 27 11:16:33] DEBUG[3200] app_unimrcp.c: Receive SIP Event [nua_i_state] Status 200 to BYE
[Sep 27 11:16:33] NOTICE[3200] app_unimrcp.c: SIP Call State 0xa5236d0 [terminated]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [1;1]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Session Terminated 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:33] DEBUG[3202] app_unimrcp.c: Process Poller Wakeup [MRCPv2-Agent-1]
[Sep 27 11:16:33] DEBUG[3202] app_unimrcp.c: Process Message [MRCPv2-Agent-1] [1;0]
[Sep 27 11:16:33] DEBUG[3202] app_unimrcp.c: Remove Control Channel <a02f9a94980c4c02@speechrecog> [0]
[Sep 27 11:16:33] DEBUG[3202] app_unimrcp.c: Close TCP/MRCPv2 Connection 127.0.0.1:41900 <-> 127.0.0.1:1544
[Sep 27 11:16:33] DEBUG[3202] app_unimrcp.c: Signal Message to [MRCP Client] [2;2]
[Sep 27 11:16:33] DEBUG[3202] app_unimrcp.c: Wait for Messages [MRCPv2-Agent-1]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [2;2]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Control Channel Removed 0xa5236d0 <a02f9a94980c4c02@speechrecog>
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]
[Sep 27 11:16:33] DEBUG[3203] app_unimrcp.c: Process Message [Media-Engine-1] [1;0]
[Sep 27 11:16:33] DEBUG[3203] app_unimrcp.c: Destroy Audio Bridge 0xa5236d0
[Sep 27 11:16:33] DEBUG[3203] app_unimrcp.c: Close RTP Transmitter 127.0.0.1:4004 -> 127.0.0.1:5000 [s:1192 o:190720]
[Sep 27 11:16:33] DEBUG[3203] app_unimrcp.c: Remove Media Context 0xa5236d0
[Sep 27 11:16:33] DEBUG[3203] app_unimrcp.c: Remove RTP Session 127.0.0.1:4004
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Process Message [MRCP Client] [3;0]
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Media Termination Subtracted 0xa5236d0 <a02f9a94980c4c02@media-tm>
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Media Termination Subtracted 0xa5236d0 <a02f9a94980c4c02@rtp-tm>
[Sep 27 11:16:33] NOTICE[3199] app_unimrcp.c: Destroy TCP/MRCPv2 Connection 127.0.0.1:41900 <-> 127.0.0.1:1544
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Remove MRCP Handle 0xa5236d0 <a02f9a94980c4c02>
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Raise App Response 0xa5236d0 <a02f9a94980c4c02> [1] SUCCESS [0]
[Sep 27 11:16:33] DEBUG[3199] res_speech_unimrcp.c: Received message from client stack
[Sep 27 11:16:33] DEBUG[3199] res_speech_unimrcp.c: On session terminate
[Sep 27 11:16:33] DEBUG[3379] res_speech_unimrcp.c: Waked up, status code: 0
[Sep 27 11:16:33] NOTICE[3379] app_unimrcp.c: Destroy MRCP Handle 0xa5236d0
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:     -- Executing [h@from-internal:1] Macro("SIP/4001-00000006", "hangupcall") in new stack
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:     -- Executing [s@macro-hangupcall:1] GotoIf("SIP/4001-00000006", "1?skiprg") in new stack
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:     -- Goto (macro-hangupcall,s,4)
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:     -- Executing [s@macro-hangupcall:4] GotoIf("SIP/4001-00000006", "1?skipblkvm") in new stack
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:     -- Goto (macro-hangupcall,s,7)
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:     -- Executing [s@macro-hangupcall:7] GotoIf("SIP/4001-00000006", "1?theend") in new stack
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:     -- Goto (macro-hangupcall,s,9)
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:     -- Executing [s@macro-hangupcall:9] Hangup("SIP/4001-00000006", "") in new stack
[Sep 27 11:16:33] VERBOSE[3379] app_macro.c:   == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/4001-00000006' in macro 'hangupcall'
[Sep 27 11:16:33] VERBOSE[3379] pbx.c:   == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/4001-00000006' 
[Sep 27 11:16:33] DEBUG[3199] app_unimrcp.c: Wait for Messages [MRCP Client]

When unimrcp waits for my input the partial result shows what i say, but it
doesn't return it. I noticed the warning message, and i've been looking for
that error, and nothing yet. Also, unimrcpserver stops sometimes when i hangup
the call. this is what it throws:

2011-09-27 11:09:10:200444 [INFO]   Process DEACTIVATE Response <6a1cc98d57a746ab@speechrecog> [10]
2011-09-27 11:09:10:200481 [INFO]   State Transition RECOGNIZING -> IDLE <6a1cc98d57a746ab@speechrecog>
2011-09-27 11:09:10:200492 [INFO]   Terminate Session 0x865a120 <6a1cc98d57a746ab>
2011-09-27 11:09:10:200520 [INFO]   Close Channel <6a1cc98d57a746ab@pocketsphinx>
2011-09-27 11:09:10:200546 [INFO]   Remove Control Channel <6a1cc98d57a746ab@speechrecog> [0]
2011-09-27 11:09:10:200605 [NOTICE] Remove Session <6a1cc98d57a746ab>
2011-09-27 11:09:10:200622 [INFO]   Remove Grammar File [../data/6a1cc98d57a746ab-digit.gram] <6a1cc98d57a746ab@pocketsphinx>
2011-09-27 11:09:10:200749 [INFO]   Free Decoder <6a1cc98d57a746ab@pocketsphinx>
2011-09-27 11:09:10:208880 [INFO]   Close RTP Receiver 127.0.0.1:5000 <- 127.0.0.1:4002 [r:6720 l:0 j:20 d:0 i:0]
2011-09-27 11:09:10:208947 [INFO]   Remove RTP Session 127.0.0.1:5000
2011-09-27 11:09:10:212231 [NOTICE] Destroy TCP/MRCPv2 Connection 127.0.0.1:1544 <-> 127.0.0.1:36430
2011-09-27 11:09:10:212402 [INFO]   Session Terminated 0x865a120 <6a1cc98d57a746ab>
2011-09-27 11:09:10:212479 [NOTICE] Destroy Session <6a1cc98d57a746ab>
*** glibc detected *** ./unimrcpserver: double free or corruption (!prev): 0x0865e308 ***
======= Backtrace: =========
/lib/libc.so.6[0x53a6c5]
/lib/libc.so.6(cfree+0x59)[0x53ab09]
/usr/local/apr/lib/libapr-1.so.0(apr_pool_destroy+0x192)[0x37f902]
/usr/local/apr/lib/libapr-1.so.0(apr_thread_exit+0x25)[0x38bf15]
../plugin/mrcppocketsphinx.so[0x84520a]
/usr/local/apr/lib/libapr-1.so.0[0x38bc86]
/lib/libpthread.so.0[0x273832]
/lib/libc.so.6(clone+0x5e)[0x5a346e]
======= Memory map: ========
00110000-00253000 r-xp 00000000 fd:00 7289744    /usr/local/lib/libsofia-sip-ua.so.0.6.0
00253000-00260000 rwxp 00143000 fd:00 7289744    /usr/local/lib/libsofia-sip-ua.so.0.6.0
00260000-00263000 r-xp 00000000 fd:00 196433     /lib/libdl-2.5.so
00263000-00264000 r-xp 00002000 fd:00 196433     /lib/libdl-2.5.so
00264000-00265000 rwxp 00003000 fd:00 196433     /lib/libdl-2.5.so
00265000-0026c000 r-xp 00000000 fd:00 196455     /lib/librt-2.5.so
0026c000-0026d000 r-xp 00007000 fd:00 196455     /lib/librt-2.5.so
0026d000-0026e000 rwxp 00008000 fd:00 196455     /lib/librt-2.5.so
0026e000-00283000 r-xp 00000000 fd:00 196451     /lib/libpthread-2.5.so
00283000-00284000 r-xp 00015000 fd:00 196451     /lib/libpthread-2.5.so
00284000-00285000 rwxp 00016000 fd:00 196451     /lib/libpthread-2.5.so
00285000-00287000 rwxp 00285000 00:00 0
00287000-0031b000 r-xp 00000000 fd:00 7280717    /usr/lib/libkrb5.so.3.3
0031b000-0031e000 rwxp 00093000 fd:00 7280717    /usr/lib/libkrb5.so.3.3
0031e000-00320000 r-xp 00000000 fd:00 196597     /lib/libcom_err.so.2.1
00320000-00321000 rwxp 00001000 fd:00 196597     /lib/libcom_err.so.2.1
00321000-00347000 r-xp 00000000 fd:00 7280707    /usr/lib/libk5crypto.so.3.1
00347000-00348000 rwxp 00025000 fd:00 7280707    /usr/lib/libk5crypto.so.3.1
00348000-00358000 r-xp 00000000 fd:00 196453     /lib/libresolv-2.5.so
00358000-00359000 r-xp 0000f000 fd:00 196453     /lib/libresolv-2.5.so
00359000-0035a000 rwxp 00010000 fd:00 196453     /lib/libresolv-2.5.so
0035a000-0035c000 rwxp 0035a000 00:00 0
0035c000-00364000 r-xp 00000000 fd:00 7280719    /usr/lib/libkrb5support.so.0.1
00364000-00365000 rwxp 00007000 fd:00 7280719    /usr/lib/libkrb5support.so.0.1
00365000-00367000 r-xp 00000000 fd:00 7856868    /usr/local/unimrcp/plugin/demosynth.so.0.0.0
00367000-00368000 rwxp 00001000 fd:00 7856868    /usr/local/unimrcp/plugin/demosynth.so.0.0.0
00369000-0038f000 r-xp 00000000 fd:00 7856692    /usr/local/apr/lib/libapr-1.so.0.4.5
0038f000-00390000 rwxp 00026000 fdAbortado

0038f000-00390000 rwxp 00026000 fdAbortado

It says that unimrcp might be corrupted, if it is, what might be a solution
for it? could that be the reason of my problem?.
or it's a single configuration error?

Thank's for your help!

Nickolay V. Shmyrev - 2011-09-27

if it is, what might be a solution for it? could that be the reason of my
problem?.

synthesis engine demo-synth is not initialized properly most likely because it
has no permission to read files like demo-8kHz.pcm in a data directory. Most
likely you didn't place them into proper location. It should be visible in the
log before pocketsphinx initialization.

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Anonymous - 2011-09-27

Sorry, don't understand what you said, and sorry for my ignorance, but what
does demo-synth got to do with recognizer?. I haven't move anything, and denie
permission to any files. That's why i don't understand, and why i'm not
getting the result. I read about lattience for a while, and i it can't find
the best path, it means that it doesn't load the graph or i'm not
specificating the location of that graph. Another thing, how does pocketsphinx
knows the lenguage model if i'm not giving any location to it?

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Anonymous - 2011-09-27

I'll only leave enable pocketsphinx engine, I just want that unimrcp allow me
to comunicate me with asterisk. I'll try it and let you know

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Nickolay V. Shmyrev - 2011-09-28

but what does demo-synth got to do with recognizer?. I haven't move
anything, and denie permission to any files. That's why i don't understand,
and why i'm not getting the result.

It's not related. You don't get the result because synthesis part is broken.
Recognizer works as expected.

Another thing, how does pocketsphinx knows the language model if i'm not
giving any location to it?

You are giving the paths to the acoustic model (Communicator) to the
dictionary (default.dic) and to the grammar (.jsgf file). It's enough to
specify the language.

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Anonymous - 2011-09-28

You don't get the result because synthesis part is broken

I tried disabling all the others engine, still no result. So should i download
again unimrcp1.0.0? try another version?

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Anonymous - 2011-09-28

this seems to be the problem nsh:

[Sep 28 08:27:35] WARNING[4780] app_unimrcp.c: Failed to terminate NLSML parsing [Sep 28 08:27:35] WARNING[4780] res_speech_unimrcp.c: Failed to load NLSML document

unimrcp is returning this document:

<?xml version="1.0"?> <result grammar="digit"> <interpretation grammar="digit" confidence="99"> <input mode="speech">three one</input> </interpretation> </result>

it contains the exact input that i gave. Really impressed with the accuracy,
but i think that that warning is the last problem, at least to get some result
input back to asterisk.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Hi nsh! i finally got something back to asterisk, it's recognizing right now.
The issues that i had were bugs that were fixed in some revisions. Just had to
change some source files in unimrcp1.0.0 dir, run make and make install. The
crashing problem and the failed to load nlsml document error are no longer
problem. This is my asterisk log now (the rest still the same):

[Sep 28 10:40:44] NOTICE[17225] res_speech_unimrcp.c: Get result '8cbe15f4a1a84d10'
[Sep 28 10:40:44] NOTICE[17225] res_speech_unimrcp.c: Interpreted instance:one score:9900 grammar:none
[Sep 28 10:40:44] VERBOSE[17225] pbx.c:     -- Executing [5551@from-internal:6] Verbose("SIP/4001-00000000", "1,Fernando es 1 y one y 9900 y ") in new stack
[Sep 28 10:40:44] VERBOSE[17225] app_verbose.c:  Fernando es 1 y one y 9900 y
[Sep 28 10:40:44] VERBOSE[17225] pbx.c:     -- Executing [5551@from-internal:7] GotoIf("SIP/4001-00000000", "0?8:10") in new stack
[Sep 28 10:40:44] VERBOSE[17225] pbx.c:     -- Goto (from-internal,5551,10)
[Sep 28 10:40:44] VERBOSE[17225] pbx.c:     -- Executing [5551@from-internal:10] Verbose("SIP/4001-00000000", "1,The recognized input is one") in new stack
[Sep 28 10:40:44] VERBOSE[17225] app_verbose.c:  The recognized input is one
[Sep 28 10:40:44] VERBOSE[17225] pbx.c:     -- Executing [5551@from-internal:11] Verbose("SIP/4001-00000000", "1,The score is 9900") in new stack
[Sep 28 10:40:44] VERBOSE[17225] app_verbose.c:  The score is 9900
[Sep 28 10:40:44] VERBOSE[17225] pbx.c:     -- Executing [5551@from-internal:12] Verbose("SIP/4001-00000000", "1,The matched grammar is ") in new stack
[Sep 28 10:40:44] VERBOSE[17225] app_verbose.c:  The matched grammar is
[Sep 28 10:40:44] VERBOSE[17225] pbx.c:     -- Executing [5551@from-internal:13] SpeechDeactivateGrammar("SIP/4001-00000000", "digit") in new stack
[Sep 28 10:40:44] NOTICE[17225] res_speech_unimrcp.c: Deactivate grammar name:digit '8cbe15f4a1a84d10'
[Sep 28 10:40:44] VERBOSE[17225] pbx.c:     -- Executing [5551@from-internal:14] SpeechUnloadGrammar("SIP/4001-00000000", "digit") in new stack
[Sep 28 10:40:44] NOTICE[17225] res_speech_unimrcp.c: Unload grammar name:digit '8cbe15f4a1a84d10'

Thank's so much for your help! couldn't make it work without your help.

Now nsh, It's there a way to get the same, but in spanish???, at least i need
that pocketsphinx recognize the natural numbers. Thank you so much!

Nickolay V. Shmyrev - 2011-09-28

Now nsh, It's there a way to get the same, but in spanish???, at least i
need that pocketsphinx recognize the natural numbers. Thank you so much!

Spanish model is available in downloads. it includes the dictionary and you
need to update jsgf grammar accordingly.

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Asterisk+Unimrcp+pocketsphinx

Speech Recognition Toolkit

Forums

Help

Asterisk+Unimrcp+pocketsphinx document.SUBSCRIPTION_OPTIONS = { "thing": "topic", "subscribed": false, "url": "subscribe", "icon": { "css": "fa fa-envelope-o" } };

Asterisk+Unimrcp+pocketsphinx