Menu

problems with unimrcp, asterisk and pocketsphinx plugin

Help
hagai sela
2012-10-12
2012-11-01
  • hagai sela

    hagai sela - 2012-10-12

    Hi,
    I have an acoustic model that recognizes hebrew digits, and it works with the pocketsphinx command line utilities.
    I am now trying to integrate it with unimrcp and asterisk, and I a problem. unimrcp returns a recognition result to asterisk before I get a chance to say anything. I also tried to use the default digit grammar that comes with unimrcp and the hub4wsj_sc_8k acoustic model from pocketsphinx and got similar results.

    This is the output from unimrcpserver and pocketsphinx:

    2012-10-12 13:28:19:288394 [NOTICE] UniMRCP Server [1.0.0]
    2012-10-12 13:28:19:288494 [INFO]   APR [1.4.5]
    2012-10-12 13:28:19:288541 [NOTICE] Create MRCP Server
    2012-10-12 13:28:19:288604 [NOTICE] Open Config File [../conf/unimrcpserver.xml]
    2012-10-12 13:28:19:288826 [DEBUG]  Loading Properties
    2012-10-12 13:28:19:288862 [DEBUG]  Loading Element <ip>
    2012-10-12 13:28:19:288887 [INFO]   Set Property ip:109.226.9.188
    2012-10-12 13:28:19:288926 [INFO]   Register Codec [PCMU]
    2012-10-12 13:28:19:288955 [INFO]   Register Codec [PCMA]
    2012-10-12 13:28:19:288982 [INFO]   Register Codec [L16]
    2012-10-12 13:28:19:289055 [DEBUG]  Loading Components
    2012-10-12 13:28:19:289088 [DEBUG]  Loading Resources
    2012-10-12 13:28:19:289143 [NOTICE] Register Resource [speechsynth]
    2012-10-12 13:28:19:289192 [NOTICE] Register Resource [speechrecog]
    2012-10-12 13:28:19:289225 [NOTICE] Register Resource [recorder]
    2012-10-12 13:28:19:289254 [INFO]   Register Resource Factory
    2012-10-12 13:28:19:289289 [DEBUG]  Loading SofiaSIP Agent <SIP-Agent-1>
    2012-10-12 13:28:19:289315 [DEBUG]  Loading Element <sip-port>
    2012-10-12 13:28:19:289349 [DEBUG]  Loading Element <sip-transport>
    2012-10-12 13:28:19:289378 [DEBUG]  Loading Element <ua-name>
    2012-10-12 13:28:19:289406 [DEBUG]  Loading Element <sdp-origin>
    2012-10-12 13:28:19:289441 [NOTICE] Create SofiaSIP Agent [SIP-Agent-1] [1.12.11devel] sip:109.226.9.188:8060;transport=udp,tcp
    2012-10-12 13:28:19:289474 [INFO]   Register Signaling Agent [SIP-Agent-1]
    2012-10-12 13:28:19:289507 [DEBUG]  Loading UniRTSP Agent <RTSP-Agent-1>
    2012-10-12 13:28:19:289533 [DEBUG]  Loading Element <rtsp-port>
    2012-10-12 13:28:19:289562 [DEBUG]  Loading Element <resource-map>
    2012-10-12 13:28:19:289589 [DEBUG]  Loading Resource Map
    2012-10-12 13:28:19:289612 [DEBUG]  Loading Param speechsynth:speechsynthesizer
    2012-10-12 13:28:19:289643 [DEBUG]  Loading Param speechrecog:speechrecognizer
    2012-10-12 13:28:19:289674 [DEBUG]  Loading Element <max-connection-count>
    2012-10-12 13:28:19:289699 [DEBUG]  Loading Element <sdp-origin>
    2012-10-12 13:28:19:289731 [DEBUG]  Create RTSP Server 109.226.9.188:1554 [100]
    2012-10-12 13:28:19:289853 [NOTICE] Create UniRTSP Agent [RTSP-Agent-1] 109.226.9.188:1554 [100]
    2012-10-12 13:28:19:289891 [INFO]   Register Signaling Agent [RTSP-Agent-1]
    2012-10-12 13:28:19:289918 [DEBUG]  Loading MRCPv2 Agent <MRCPv2-Agent-1>
    2012-10-12 13:28:19:289943 [DEBUG]  Loading Element <mrcp-port>
    2012-10-12 13:28:19:289971 [DEBUG]  Loading Element <max-connection-count>
    2012-10-12 13:28:19:290029 [DEBUG]  Loading Element <force-new-connection>
    2012-10-12 13:28:19:290073 [DEBUG]  Loading Element <rx-buffer-size>
    2012-10-12 13:28:19:290113 [DEBUG]  Loading Element <tx-buffer-size>
    2012-10-12 13:28:19:290146 [NOTICE] Create MRCPv2 Agent [MRCPv2-Agent-1] 109.226.9.188:1544 [100]
    2012-10-12 13:28:19:290218 [INFO]   Register Connection Agent [MRCPv2-Agent-1]
    2012-10-12 13:28:19:290258 [DEBUG]  Loading Media Engine <Media-Engine-1>
    2012-10-12 13:28:19:290284 [DEBUG]  Loading Element <realtime-rate>
    2012-10-12 13:28:19:290313 [NOTICE] Create Media Engine [Media-Engine-1]
    2012-10-12 13:28:19:290343 [INFO]   Register Media Engine [Media-Engine-1]
    2012-10-12 13:28:19:290371 [DEBUG]  Loading RTP Factory <RTP-Factory-1>
    2012-10-12 13:28:19:290396 [DEBUG]  Loading Element <rtp-port-min>
    2012-10-12 13:28:19:290423 [DEBUG]  Loading Element <rtp-port-max>
    2012-10-12 13:28:19:290451 [NOTICE] Create RTP Termination Factory 109.226.9.188:[5000,6000]
    2012-10-12 13:28:19:290476 [INFO]   Register RTP Termination Factory [RTP-Factory-1]
    2012-10-12 13:28:19:290503 [DEBUG]  Loading Plugin Factory
    2012-10-12 13:28:19:290526 [DEBUG]  Loading Element <engine>
    2012-10-12 13:28:19:290552 [INFO]   Load Plugin [PocketSphinx-1] [../plugin/mrcppocketsphinx.so]
    2012-10-12 13:28:19:291367 [INFO]   Create PocketSphinx Engine
    2012-10-12 13:28:19:291414 [INFO]   Register MRCP Engine [PocketSphinx-1]
    2012-10-12 13:28:19:291442 [DEBUG]  Loading Element <engine>
    2012-10-12 13:28:19:291466 [DEBUG]  Loading Element <engine>
    2012-10-12 13:28:19:291489 [DEBUG]  Loading Element <engine>
    2012-10-12 13:28:19:291512 [DEBUG]  Loading Element <engine>
    2012-10-12 13:28:19:291535 [DEBUG]  Loading Settings
    2012-10-12 13:28:19:291561 [DEBUG]  Loading RTP Settings <RTP-Settings-1>
    2012-10-12 13:28:19:291585 [DEBUG]  Loading Element <jitter-buffer>
    2012-10-12 13:28:19:291611 [DEBUG]  Loading Jitter Buffer Settings
    2012-10-12 13:28:19:291637 [DEBUG]  Loading Element <playout-delay>
    2012-10-12 13:28:19:291664 [DEBUG]  Loading Element <max-playout-delay>
    2012-10-12 13:28:19:291689 [DEBUG]  Loading Element <ptime>
    2012-10-12 13:28:19:291713 [DEBUG]  Loading Element <codecs>
    2012-10-12 13:28:19:291741 [DEBUG]  Loading Element <rtcp>
    2012-10-12 13:28:19:291767 [INFO]   Register RTP Settings [RTP-Settings-1]
    2012-10-12 13:28:19:291793 [DEBUG]  Loading Profiles
    2012-10-12 13:28:19:291818 [DEBUG]  Loading MRCPv2 Profile <uni2>
    2012-10-12 13:28:19:291845 [DEBUG]  Loading Element <sip-uas>
    2012-10-12 13:28:19:291874 [DEBUG]  Loading Element <mrcpv2-uas>
    2012-10-12 13:28:19:291903 [DEBUG]  Loading Element <media-engine>
    2012-10-12 13:28:19:291936 [DEBUG]  Loading Element <rtp-factory>
    2012-10-12 13:28:19:291967 [DEBUG]  Loading Element <rtp-settings>
    2012-10-12 13:28:19:292030 [NOTICE] Create MRCPv2 Profile [uni2]
    2012-10-12 13:28:19:292088 [WARN]   No MRCP Engine Available [speechsynth]
    2012-10-12 13:28:19:292121 [INFO]   Assign MRCP Engine [speechrecog] [PocketSphinx-1]
    2012-10-12 13:28:19:292147 [WARN]   No MRCP Engine Available [recorder]
    2012-10-12 13:28:19:292170 [INFO]   Register Profile [uni2]
    2012-10-12 13:28:19:292191 [DEBUG]  Loading MRCPv1 Profile <uni1>
    2012-10-12 13:28:19:292214 [DEBUG]  Loading Element <rtsp-uas>
    2012-10-12 13:28:19:292239 [DEBUG]  Loading Element <media-engine>
    2012-10-12 13:28:19:292263 [DEBUG]  Loading Element <rtp-factory>
    2012-10-12 13:28:19:292286 [DEBUG]  Loading Element <rtp-settings>
    2012-10-12 13:28:19:292310 [NOTICE] Create MRCPv1 Profile [uni1]
    2012-10-12 13:28:19:292334 [WARN]   No MRCP Engine Available [speechsynth]
    2012-10-12 13:28:19:292356 [INFO]   Assign MRCP Engine [speechrecog] [PocketSphinx-1]
    2012-10-12 13:28:19:292379 [WARN]   No MRCP Engine Available [recorder]
    2012-10-12 13:28:19:292401 [INFO]   Register Profile [uni1]
    2012-10-12 13:28:19:292423 [INFO]   Start Task [MRCP Server]
    >2012-10-12 13:28:19:292539 [INFO]   Open Engine [PocketSphinx-1]
    2012-10-12 13:28:19:292573 [DEBUG]  Open PocketSphinx Config File [../conf/pocketsphinx.xml]
    2012-10-12 13:28:19:292660 [WARN]   Unknown Attribute <timeout>
    2012-10-12 13:28:19:292700 [DEBUG]  Signal Message to [MRCP Server] [3;0]
    2012-10-12 13:28:19:292727 [INFO]   Start Task [SIP-Agent-1]
    2012-10-12 13:28:19:292767 [INFO]   Start Task [RTSP-Agent-1]
    2012-10-12 13:28:19:292822 [INFO]   Start Task [MRCPv2-Agent-1]
    2012-10-12 13:28:19:292873 [INFO]   Start Task [Media-Engine-1]
    2012-10-12 13:28:19:292924 [DEBUG]  Task Started [Media-Engine-1]
    2012-10-12 13:28:19:292954 [DEBUG]  Signal Message to [MRCP Server] [0;1]
    2012-10-12 13:28:19:294405 [DEBUG]  Task Started [SIP-Agent-1]
    2012-10-12 13:28:19:294512 [DEBUG]  Signal Message to [MRCP Server] [0;1]
    2012-10-12 13:28:19:294539 [INFO]   Receive SIP Event [nua_r_set_params] Status 200 OK
    2012-10-12 13:28:19:293155 [DEBUG]  Task Started [RTSP-Agent-1]
    2012-10-12 13:28:19:294598 [DEBUG]  Signal Message to [MRCP Server] [0;1]
    2012-10-12 13:28:19:294621 [DEBUG]  Wait for Messages [RTSP-Agent-1]
    2012-10-12 13:28:19:294461 [DEBUG]  Task Started [MRCPv2-Agent-1]
    2012-10-12 13:28:19:294674 [DEBUG]  Signal Message to [MRCP Server] [0;1]
    2012-10-12 13:28:19:294696 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:19:292988 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:19:294769 [DEBUG]  Process Message [MRCP Server] [3;0]
    2012-10-12 13:28:19:294796 [DEBUG]  Engine Opened [PocketSphinx-1] status [success]
    2012-10-12 13:28:19:294824 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:19:294848 [DEBUG]  Process Message [MRCP Server] [0;1]
    2012-10-12 13:28:19:294871 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:19:294894 [DEBUG]  Process Message [MRCP Server] [0;1]
    2012-10-12 13:28:19:294917 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:19:294957 [DEBUG]  Process Message [MRCP Server] [0;1]
    2012-10-12 13:28:19:295023 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:19:295054 [DEBUG]  Process Message [MRCP Server] [0;1]
    2012-10-12 13:28:19:295077 [DEBUG]  Task Started [MRCP Server]
    2012-10-12 13:28:19:295102 [NOTICE] MRCP Server Started
    2012-10-12 13:28:19:295124 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:31:946929 [INFO]   Receive SIP Event [nua_i_invite] Status 100 Trying
    2012-10-12 13:28:31:947011 [INFO]   Receive SIP Event [nua_i_state] Status 100 Trying
    2012-10-12 13:28:31:947055 [NOTICE] SIP Call State  [received]
    2012-10-12 13:28:31:947117 [INFO]   Create Session 0x1d590eb8 <new> [uni2]
    2012-10-12 13:28:31:947156 [INFO]   Remote SDP 0x1d590eb8 <new>
    v=0
    
    o=UniMRCPClient 3079121743079015827 4738055213848797194 IN IP4 109.226.9.188
    
    s=-
    
    c=IN IP4 109.226.9.188
    
    t=0 0
    
    m=application 9 TCP/MRCPv2 1
    
    a=setup:active
    
    a=connection:new
    
    a=resource:speechrecog
    
    a=cmid:1
    
    m=audio 4002 RTP/AVP 0 8 96 101
    
    a=rtpmap:0 PCMU/8000
    
    a=rtpmap:8 PCMA/8000
    
    a=rtpmap:96 L16/8000
    
    a=rtpmap:101 telephone-event/8000
    
    a=fmtp:101 0-15
    
    a=sendonly
    
    a=ptime:20
    
    a=mid:1
    
    2012-10-12 13:28:31:947255 [DEBUG]  Process Message [MRCP Server] [1;0]
    2012-10-12 13:28:31:947290 [DEBUG]  Dispatch Signaling Message [0]
    2012-10-12 13:28:31:947350 [NOTICE] Add Session <f3cfe720145f11e2>
    2012-10-12 13:28:31:947391 [INFO]   Receive Offer 0x1d590eb8 <f3cfe720145f11e2> [c:1 a:1 v:0]
    2012-10-12 13:28:31:947447 [DEBUG]  Add Control Channel 0x1d590eb8 <f3cfe720145f11e2@speechrecog> [0]
    2012-10-12 13:28:31:947480 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:31:947570 [DEBUG]  Add Media Termination 0x1d590eb8 <f3cfe720145f11e2@rtp-tm> [0]
    2012-10-12 13:28:31:947615 [DEBUG]  Signal Message to [Media-Engine-1] [1;0]
    2012-10-12 13:28:31:947642 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:31:947709 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
    2012-10-12 13:28:31:947741 [DEBUG]  Process Message [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:31:947772 [DEBUG]  Create Container for Pending Control Channels
    2012-10-12 13:28:31:947811 [INFO]   Add Pending Control Channel <f3cfe720145f11e2@speechrecog> [1]
    2012-10-12 13:28:31:947844 [DEBUG]  Signal Message to [MRCP Server] [2;0]
    2012-10-12 13:28:31:947899 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:31:947954 [DEBUG]  Process Message [MRCP Server] [2;0]
    2012-10-12 13:28:31:948007 [DEBUG]  Control Channel Modified 0x1d590eb8 <f3cfe720145f11e2@speechrecog>
    2012-10-12 13:28:31:948055 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:31:954701 [DEBUG]  Process Message [Media-Engine-1] [1;0]
    2012-10-12 13:28:31:954720 [DEBUG]  Add Media Context 0x1d590eb8
    2012-10-12 13:28:31:954821 [INFO]   Enable RTP Session 109.226.9.188:5000
    2012-10-12 13:28:31:954888 [DEBUG]  Create Linear Audio Bridge 0x1d590eb8
    2012-10-12 13:28:31:954897 [INFO]   Open RTP Receiver 109.226.9.188:5000 <- 109.226.9.188:4002 playout [50 ms]
    2012-10-12 13:28:31:954903 [INFO]   Media Path 0x1d590eb8 Source->[PCMU/8000/1]->Decoder->[LPCM/8000/1]->Bridge->[LPCM/8000/1]->Sink
    2012-10-12 13:28:31:954966 [DEBUG]  Process Message [MRCP Server] [4;0]
    2012-10-12 13:28:31:954997 [DEBUG]  Media Termination Modified 0x1d590eb8 <f3cfe720145f11e2@media-tm>
    2012-10-12 13:28:31:955025 [DEBUG]  Media Termination Modified 0x1d590eb8 <f3cfe720145f11e2@rtp-tm>
    2012-10-12 13:28:31:955064 [INFO]   Open Channel <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:31:955130 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:31:955171 [INFO]   Run Recognition Thread <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:31:955202 [DEBUG]  Signal Message to [MRCP Server] [3;2]
    2012-10-12 13:28:31:955232 [DEBUG]  Process Message [MRCP Server] [3;2]
    2012-10-12 13:28:31:955260 [DEBUG]  Engine Channel Opened 0x1d590eb8 <f3cfe720145f11e2@speechrecog> [OK]
    2012-10-12 13:28:31:955287 [INFO]   Send Answer 0x1d590eb8 <f3cfe720145f11e2> [c:1 a:1 v:0] Status OK
    2012-10-12 13:28:31:955329 [INFO]   Local SDP 0x1d590eb8 <f3cfe720145f11e2>
    v=0
    
    o=UniMRCPServer 0 0 IN IP4 109.226.9.188
    
    s=-
    
    c=IN IP4 109.226.9.188
    
    t=0 0
    
    m=application 1544 TCP/MRCPv2 1
    
    a=setup:passive
    
    a=connection:new
    
    a=channel:f3cfe720145f11e2@speechrecog
    
    a=cmid:1
    
    m=audio 5000 RTP/AVP 0 101
    
    a=rtpmap:0 PCMU/8000
    
    a=rtpmap:101 telephone-event/8000
    
    a=fmtp:101 0-15
    
    a=recvonly
    
    a=ptime:20
    
    a=mid:1
    
    2012-10-12 13:28:31:955392 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:31:956178 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK
    2012-10-12 13:28:31:956222 [NOTICE] SIP Call State 0x1d590eb8 [completed]
    2012-10-12 13:28:31:956251 [INFO]   Receive SIP Event [nua_i_ack] Status 200 OK
    2012-10-12 13:28:31:956289 [INFO]   Receive SIP Event [nua_i_state] Status 200 OK
    2012-10-12 13:28:31:956319 [NOTICE] SIP Call State 0x1d590eb8 [ready]
    2012-10-12 13:28:31:956347 [INFO]   Receive SIP Event [nua_i_active] Status 200 Call active
    2012-10-12 13:28:31:956377 [DEBUG]  Process Signalled Descriptor [MRCPv2-Agent-1]
    2012-10-12 13:28:31:956431 [NOTICE] Accepted TCP/MRCPv2 Connection 109.226.9.188:1544 <-> 109.226.9.188:49288
    2012-10-12 13:28:31:956490 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:31:956436 [DEBUG]  Wait for incoming messages <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:31:966320 [DEBUG]  Process Signalled Descriptor [MRCPv2-Agent-1]
    2012-10-12 13:28:31:966395 [INFO]   Receive MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [132 bytes]
    MRCP/2.0 132 SET-PARAMS 1
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    Recognition-Timeout: 20000
    
    No-Input-Timeout: 15000
    
    2012-10-12 13:28:31:966484 [INFO]   Attach Control Channel <f3cfe720145f11e2@speechrecog> to Connection 109.226.9.188:1544 <-> 109.226.9.188:49288 [1]
    2012-10-12 13:28:31:966523 [DEBUG]  Signal Message to [MRCP Server] [2;3]
    2012-10-12 13:28:31:966552 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:31:966582 [DEBUG]  Process Message [MRCP Server] [2;3]
    2012-10-12 13:28:31:966613 [DEBUG]  Dispatch Signaling Message [1]
    2012-10-12 13:28:31:966687 [INFO]   Process SET-PARAMS Request <f3cfe720145f11e2@speechrecog> [1]
    2012-10-12 13:28:31:966748 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:31:966784 [INFO]   Dispatch Request SET-PARAMS <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:31:966816 [DEBUG]  Signal Message to [MRCP Server] [3;4]
    2012-10-12 13:28:31:966848 [DEBUG]  Process Message [MRCP Server] [3;4]
    2012-10-12 13:28:31:966896 [INFO]   Process SET-PARAMS Response <f3cfe720145f11e2@speechrecog> [1]
    2012-10-12 13:28:31:966949 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:31:966982 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:31:967014 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
    2012-10-12 13:28:31:967040 [DEBUG]  Process Message [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:31:967075 [INFO]   Send MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [80 bytes]
    MRCP/2.0 80 1 200 COMPLETE
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    2012-10-12 13:28:31:967161 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:31:967204 [DEBUG]  Wait for incoming messages <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:31:967690 [DEBUG]  Process Signalled Descriptor [MRCPv2-Agent-1]
    2012-10-12 13:28:31:967739 [INFO]   Receive MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [361 bytes]
    MRCP/2.0 361 DEFINE-GRAMMAR 2
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    Content-Type: application/x-jsgf
    
    Content-Id: grammar
    
    Content-Length: 202
    
    #JSGF V1.0;
    
    /**
    
     * JSGF Digits Grammar for Hello World example
    
     */
    
    grammar digits;
    
    public<numbers> = (EFES | ACHAT | SHTAYIM | SHALOSH | ARBA | CHAMESH | 
    SHESH | SHEVA | SHMONNE | TESHA) * ;
    
    2012-10-12 13:28:31:967883 [DEBUG]  Signal Message to [MRCP Server] [2;3]
    2012-10-12 13:28:31:967963 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:31:968033 [DEBUG]  Process Message [MRCP Server] [2;3]
    2012-10-12 13:28:31:968081 [DEBUG]  Dispatch Signaling Message [1]
    2012-10-12 13:28:31:968137 [INFO]   Process DEFINE-GRAMMAR Request <f3cfe720145f11e2@speechrecog> [2]
    2012-10-12 13:28:31:968174 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:31:968206 [INFO]   Dispatch Request DEFINE-GRAMMAR <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:31:968244 [INFO]   Create Grammar File [../data/f3cfe720145f11e2-grammar.gram] <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:31:968356 [DEBUG]  Init Config rate [8000] dictionary [../data/omnidict.d] <f3cfe720145f11e2@pocketsphinx>
    INFO: cmd_ln.c(691): Parsing command line:
    \
    -samprate 8000 \
    -hmm ../data/wsj8kadapt \
    -jsgf ../data/f3cfe720145f11e2-grammar.gram \
    -dict ../data/omnidict.d \
    -frate 50 \
    -silprob 0.005
    
    Current configuration:
    [NAME][DEFLT][VALUE]
    -agcnonenone
    -agcthresh2.02.000000e+00
    -alpha0.979.700000e-01
    -ascale20.02.000000e+01
    -aw11
    -backtracenono
    -beam1e-481.000000e-48
    -bestpathyesyes
    -bestpathlw9.59.500000e+00
    -bghistnono
    -ceplen1313
    -cmncurrentcurrent
    -cmninit8.08.0
    -compallsennono
    -debug0
    -dict../data/omnidict.d
    -dictcasenono
    -dithernono
    -doublebwnono
    -ds11
    -fdict
    -feat1s_c_d_dd1s_c_d_dd
    -featparams
    -fillprob1e-81.000000e-08
    -frate10050
    -fsg
    -fsgusealtpronyesyes
    -fsgusefilleryesyes
    -fwdflatyesyes
    -fwdflatbeam1e-641.000000e-64
    -fwdflatefwid44
    -fwdflatlw8.58.500000e+00
    -fwdflatsfwin2525
    -fwdflatwbeam7e-297.000000e-29
    -fwdtreeyesyes
    -hmm../data/wsj8kadapt
    -input_endianlittlelittle
    -jsgf../data/f3cfe720145f11e2-grammar.gram
    -kdmaxbbi-1-1
    -kdmaxdepth00
    -kdtree
    -latsize50005000
    -lda
    -ldadim00
    -lextreedump00
    -lifter00
    -lm
    -lmctl
    -lmnamedefaultdefault
    -logbase1.00011.000100e+00
    -logfn
    -logspecnono
    -lowerf133.333341.333333e+02
    -lpbeam1e-401.000000e-40
    -lponlybeam7e-297.000000e-29
    -lw6.56.500000e+00
    -maxhmmpf-1-1
    -maxnewoov2020
    -maxwpf-1-1
    -mdef
    -mean
    -mfclogdir
    -min_endfr00
    -mixw
    -mixwfloor0.00000011.000000e-07
    -mllr
    -mmapyesyes
    -ncep1313
    -nfft512512
    -nfilt4040
    -nwpen1.01.000000e+00
    -pbeam1e-481.000000e-48
    -pip1.01.000000e+00
    -pl_beam1e-101.000000e-10
    -pl_pbeam1e-51.000000e-05
    -pl_window00
    -rawlogdir
    -remove_dcnono
    -round_filtersyesyes
    -samprate160008.000000e+03
    -seed-1-1
    -sendump
    -senlogdir
    -senmgau
    -silprob0.0055.000000e-03
    -smoothspecnono
    -svspec
    -tmat
    -tmatfloor0.00011.000000e-04
    -topn44
    -topn_beam00
    -toprule
    -transformlegacylegacy
    -unit_areayesyes
    -upperf6855.49766.855498e+03
    -usewdphonesnono
    -uw1.01.000000e+00
    -var
    -varfloor0.00011.000000e-04
    -varnormnono
    -verbosenono
    -warp_params
    -warp_typeinverse_linearinverse_linear
    -wbeam7e-297.000000e-29
    -wip0.656.500000e-01
    -wlen0.0256252.562500e-02
    
    2012-10-12 13:28:31:973822 [INFO]   Init Decoder <f3cfe720145f11e2@pocketsphinx>
    INFO: cmd_ln.c(691): Parsing command line:
    \
    -nfilt 31 \
    -lowerf 200 \
    -upperf 3500 \
    -wlen 0.025625 \
    -feat 1s_c_d_dd \
    -agc none \
    -cmn current \
    -varnorm no
    
    Current configuration:
    [NAME][DEFLT][VALUE]
    -agcnonenone
    -agcthresh2.02.000000e+00
    -alpha0.979.700000e-01
    -ceplen1313
    -cmncurrentcurrent
    -cmninit8.08.0
    -dithernono
    -doublebwnono
    -feat1s_c_d_dd1s_c_d_dd
    -frate10050
    -input_endianlittlelittle
    -lda
    -ldadim00
    -lifter00
    -logspecnono
    -lowerf133.333342.000000e+02
    -ncep1313
    -nfft512512
    -nfilt4031
    -remove_dcnono
    -round_filtersyesyes
    -samprate160008.000000e+03
    -seed-1-1
    -smoothspecnono
    -svspec
    -transformlegacylegacy
    -unit_areayesyes
    -upperf6855.49763.500000e+03
    -varnormnono
    -verbosenono
    -warp_params
    -warp_typeinverse_linearinverse_linear
    -wlen0.0256252.562500e-02
    
    INFO: acmod.c(246): Parsed model-specific feature parameters from ../data/wsj8kadapt/feat.params
    INFO: feat.c(713): 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(517): Reading model definition: ../data/wsj8kadapt/mdef
    INFO: bin_mdef.c(179): Allocating 115403 * 8 bytes (901 KiB) for CD tree
    INFO: tmat.c(205): Reading HMM transition probability matrices: ../data/wsj8kadapt/transition_matrices
    INFO: acmod.c(121): Attempting to use SCHMM computation module
    INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/wsj8kadapt/means
    INFO: ms_gauden.c(292): 4162 codebook, 1 feature, size: 
    INFO: ms_gauden.c(294):  8x39
    INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/wsj8kadapt/variances
    INFO: ms_gauden.c(292): 4162 codebook, 1 feature, size: 
    INFO: ms_gauden.c(294):  8x39
    INFO: ms_gauden.c(354): 2507 variance values floored
    INFO: acmod.c(123): Attempting to use PTHMM computation module
    INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/wsj8kadapt/means
    INFO: ms_gauden.c(292): 4162 codebook, 1 feature, size: 
    INFO: ms_gauden.c(294):  8x39
    INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/wsj8kadapt/variances
    INFO: ms_gauden.c(292): 4162 codebook, 1 feature, size: 
    INFO: ms_gauden.c(294):  8x39
    INFO: ms_gauden.c(354): 2507 variance values floored
    INFO: ptm_mgau.c(800): Number of codebooks exceeds 256: 4162
    INFO: acmod.c(125): Falling back to general multi-stream GMM computation
    INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/wsj8kadapt/means
    INFO: ms_gauden.c(292): 4162 codebook, 1 feature, size: 
    INFO: ms_gauden.c(294):  8x39
    INFO: ms_gauden.c(198): Reading mixture gaussian parameter: ../data/wsj8kadapt/variances
    INFO: ms_gauden.c(292): 4162 codebook, 1 feature, size: 
    INFO: ms_gauden.c(294):  8x39
    INFO: ms_gauden.c(354): 2507 variance values floored
    INFO: ms_senone.c(160): Reading senone mixture weights: ../data/wsj8kadapt/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 4162 senones: 1 features x 8 codewords
    INFO: ms_senone.c(331): Mapping senones to individual codebooks
    INFO: ms_mgau.c(141): The value of topn: 4
    INFO: dict.c(317): Allocating 4143 * 32 bytes (129 KiB) for word entries
    INFO: dict.c(332): Reading main dictionary: ../data/omnidict.d
    INFO: dict.c(211): Allocated 0 KiB for strings, 0 KiB for phones
    INFO: dict.c(335): 20 words read
    INFO: dict.c(341): Reading filler dictionary: ../data/wsj8kadapt/noisedict
    INFO: dict.c(211): Allocated 0 KiB for strings, 0 KiB for phones
    INFO: dict.c(344): 27 words read
    INFO: dict2pid.c(396): Building PID tables for dictionary
    INFO: dict2pid.c(404): Allocating 54^3 * 2 bytes (307 KiB) for word-initial triphones
    INFO: dict2pid.c(131): Allocated 70416 bytes (68 KiB) for word-final triphones
    INFO: dict2pid.c(195): Allocated 70416 bytes (68 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(581): Defined rule: <digits.g00000>
    INFO: jsgf.c(581): Defined rule: <digits.g00001>
    INFO: jsgf.c(581): Defined rule: PUBLIC <digits.numbers>
    INFO: jsgf.c(353): Right recursion <digits.g00001> 6 => 2
    INFO: fsg_model.c(215): Computing transitive closure for null transitions
    INFO: fsg_model.c(270): 60 null transitions added
    INFO: fsg_model.c(421): Adding silence transitions for <sil> to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++AH++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++BEEP++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++BREATH++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++CHAIR_SQUEAK++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++CLICK++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++DISK_NOISE++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++DOOR_SLAM++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++EXHALATION++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++GRUNT++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++INHALATION++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++LAUGHTER++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++LIP_SMACK++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++LOUD_BREATH++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++MICROPHONE_MVT++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++MISC_NOISE++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++MOVEMENT++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++NOISE++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++PAPER_RUSTLE++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++PHONE_RING++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++SIGH++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++TAP++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++THROAT_CLEAR++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++TONGUE_CLICK++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for ++TYPING++ to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_model.c(421): Adding silence transitions for <sil> to FSG
    INFO: fsg_model.c(441): Added 17 silence word transitions
    INFO: fsg_search.c(366): Added 2 alternate word transitions
    INFO: fsg_lextree.c(108): Allocated 1870 bytes (1 KiB) for left and right context phones
    INFO: fsg_lextree.c(253): 520 HMM nodes in lextree (481 leaves)
    INFO: fsg_lextree.c(255): Allocated 66560 bytes (65 KiB) for all lextree nodes
    INFO: fsg_lextree.c(258): Allocated 61568 bytes (60 KiB) for lextree leafnodes
    2012-10-12 13:28:32:812808 [DEBUG]  Signal Message to [MRCP Server] [3;4]
    2012-10-12 13:28:32:812825 [DEBUG]  Wait for incoming messages <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:32:812866 [DEBUG]  Process Message [MRCP Server] [3;4]
    2012-10-12 13:28:32:812876 [INFO]   Process DEFINE-GRAMMAR Response <f3cfe720145f11e2@speechrecog> [2]
    2012-10-12 13:28:32:812882 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:32:812892 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:32:812934 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
    2012-10-12 13:28:32:812939 [DEBUG]  Process Message [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:32:812953 [INFO]   Send MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [112 bytes]
    MRCP/2.0 112 2 200 COMPLETE
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    Completion-Cause: 000 success
    
    2012-10-12 13:28:32:812981 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:32:813418 [DEBUG]  Process Signalled Descriptor [MRCPv2-Agent-1]
    2012-10-12 13:28:32:813449 [INFO]   Receive MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [192 bytes]
    MRCP/2.0 192 RECOGNIZE 3
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    Content-Type: text/uri-list
    
    Cancel-If-Queue: false
    
    Start-Input-Timers: true
    
    Content-Length: 15
    
    session:grammar
    2012-10-12 13:28:32:813482 [DEBUG]  Signal Message to [MRCP Server] [2;3]
    2012-10-12 13:28:32:813488 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:32:813540 [DEBUG]  Process Message [MRCP Server] [2;3]
    2012-10-12 13:28:32:813546 [DEBUG]  Dispatch Signaling Message [1]
    2012-10-12 13:28:32:813549 [INFO]   Process RECOGNIZE Request <f3cfe720145f11e2@speechrecog> [3]
    2012-10-12 13:28:32:813619 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:32:813672 [INFO]   Dispatch Request RECOGNIZE <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:32:813714 [DEBUG]  Signal Message to [MRCP Server] [3;4]
    2012-10-12 13:28:32:813722 [DEBUG]  Wait for incoming messages <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:32:813772 [DEBUG]  Process Message [MRCP Server] [3;4]
    2012-10-12 13:28:32:813780 [INFO]   Process RECOGNIZE Response <f3cfe720145f11e2@speechrecog> [3]
    2012-10-12 13:28:32:813783 [INFO]   State Transition IDLE -> RECOGNIZING <f3cfe720145f11e2@speechrecog>
    2012-10-12 13:28:32:813787 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:32:813793 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:32:813833 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
    2012-10-12 13:28:32:813838 [DEBUG]  Process Message [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:32:813845 [INFO]   Send MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [83 bytes]
    MRCP/2.0 83 3 200 IN-PROGRESS
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    2012-10-12 13:28:32:813868 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:33:064602 [INFO]   Detected Voice Activity <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:33:064628 [DEBUG]  Signal Message to [MRCP Server] [3;4]
    2012-10-12 13:28:33:064774 [DEBUG]  Process Message [MRCP Server] [3;4]
    2012-10-12 13:28:33:064783 [INFO]   Process START-OF-INPUT Event <f3cfe720145f11e2@speechrecog> [3]
    2012-10-12 13:28:33:064788 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:33:064798 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:33:064808 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
    2012-10-12 13:28:33:064812 [DEBUG]  Process Message [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:33:064823 [INFO]   Send MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [94 bytes]
    MRCP/2.0 94 START-OF-INPUT 3 IN-PROGRESS
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    2012-10-12 13:28:33:064856 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:33:094707 [INFO]   Detected Voice Inactivity <f3cfe720145f11e2@pocketsphinx>
    INFO: fsg_search.c(1032): 11 frames, 126 HMMs (11/fr), 300 senones (27/fr), 6 history entries (0/fr)
    
    WARNING: "fsg_search.c", line 1676: Failed to find the end node
    WARNING: "fsg_search.c", line 1162: Failed to obtain the lattice while bestpath enabled
    2012-10-12 13:28:33:094837 [DEBUG]  Signal Message to [MRCP Server] [3;4]
    2012-10-12 13:28:33:094848 [DEBUG]  Wait for incoming messages <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:33:094900 [DEBUG]  Process Message [MRCP Server] [3;4]
    2012-10-12 13:28:33:094908 [INFO]   Process RECOGNITION-COMPLETE Event <f3cfe720145f11e2@speechrecog> [3]
    2012-10-12 13:28:33:094912 [INFO]   State Transition RECOGNIZING -> RECOGNIZED <f3cfe720145f11e2@speechrecog>
    2012-10-12 13:28:33:094917 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:33:094925 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:33:094934 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
    2012-10-12 13:28:33:094937 [DEBUG]  Process Message [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:33:094945 [INFO]   Send MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [129 bytes]
    MRCP/2.0 129 RECOGNITION-COMPLETE 3 COMPLETE
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    Completion-Cause: 000 success
    
    2012-10-12 13:28:33:094982 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:33:101486 [DEBUG]  Process Signalled Descriptor [MRCPv2-Agent-1]
    2012-10-12 13:28:33:101498 [INFO]   Receive MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [104 bytes]
    MRCP/2.0 104 DEFINE-GRAMMAR 4
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    Content-Id: grammar
    
    2012-10-12 13:28:33:101517 [DEBUG]  Signal Message to [MRCP Server] [2;3]
    2012-10-12 13:28:33:101523 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:33:101614 [DEBUG]  Process Message [MRCP Server] [2;3]
    2012-10-12 13:28:33:101624 [DEBUG]  Dispatch Signaling Message [1]
    2012-10-12 13:28:33:101629 [INFO]   Process DEFINE-GRAMMAR Request <f3cfe720145f11e2@speechrecog> [4]
    2012-10-12 13:28:33:101634 [INFO]   State Transition RECOGNIZED -> IDLE <f3cfe720145f11e2@speechrecog>
    2012-10-12 13:28:33:101651 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:33:101662 [INFO]   Dispatch Request DEFINE-GRAMMAR <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:33:101674 [INFO]   Remove Grammar File [../data/f3cfe720145f11e2-grammar.gram] <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:33:101724 [DEBUG]  Signal Message to [MRCP Server] [3;4]
    2012-10-12 13:28:33:101739 [DEBUG]  Wait for incoming messages <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:33:101770 [DEBUG]  Process Message [MRCP Server] [3;4]
    2012-10-12 13:28:33:101778 [INFO]   Process DEFINE-GRAMMAR Response <f3cfe720145f11e2@speechrecog> [4]
    2012-10-12 13:28:33:101781 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:33:101787 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:33:101825 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
    2012-10-12 13:28:33:101830 [DEBUG]  Process Message [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:33:101837 [INFO]   Send MRCPv2 Stream 109.226.9.188:1544 <-> 109.226.9.188:49288 [112 bytes]
    MRCP/2.0 112 4 200 COMPLETE
    
    Channel-Identifier: f3cfe720145f11e2@speechrecog
    
    Completion-Cause: 000 success
    
    2012-10-12 13:28:33:101863 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:33:102430 [DEBUG]  Process Signalled Descriptor [MRCPv2-Agent-1]
    2012-10-12 13:28:33:102441 [INFO]   TCP/MRCPv2 Peer Disconnected 109.226.9.188:1544 <-> 109.226.9.188:49288
    2012-10-12 13:28:33:102472 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:33:102770 [INFO]   Receive SIP Event [nua_i_bye] Status 200 Session Terminated
    2012-10-12 13:28:33:102780 [INFO]   Receive SIP Event [nua_i_state] Status 200 Session Terminated
    2012-10-12 13:28:33:102785 [NOTICE] SIP Call State 0x1d590eb8 [terminated]
    2012-10-12 13:28:33:102792 [INFO]   Receive SIP Event [nua_i_terminated] Status 200 Session Terminated
    2012-10-12 13:28:33:102901 [DEBUG]  Process Message [MRCP Server] [1;2]
    2012-10-12 13:28:33:102908 [DEBUG]  Dispatch Signaling Message [2]
    2012-10-12 13:28:33:102911 [INFO]   Deactivate Session 0x1d590eb8 <f3cfe720145f11e2>
    2012-10-12 13:28:33:102914 [INFO]   Terminate Session 0x1d590eb8 <f3cfe720145f11e2>
    2012-10-12 13:28:33:102918 [DEBUG]  Remove Control Channel 0x1d590eb8 <f3cfe720145f11e2@speechrecog> [0]
    2012-10-12 13:28:33:102923 [DEBUG]  Signal Message to [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:33:102929 [DEBUG]  Subtract Media Termination 0x1d590eb8 <f3cfe720145f11e2@media-tm>
    2012-10-12 13:28:33:102932 [INFO]   Close Channel <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:33:102937 [DEBUG]  Subtract Media Termination 0x1d590eb8 <f3cfe720145f11e2@rtp-tm>
    2012-10-12 13:28:33:102940 [DEBUG]  Signal Message to [Media-Engine-1] [1;0]
    2012-10-12 13:28:33:102943 [NOTICE] Remove Session <f3cfe720145f11e2>
    2012-10-12 13:28:33:102947 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:33:102958 [INFO]   Free Decoder <f3cfe720145f11e2@pocketsphinx>
    2012-10-12 13:28:33:103018 [DEBUG]  Process Poller Wakeup [MRCPv2-Agent-1]
    2012-10-12 13:28:33:103024 [DEBUG]  Process Message [MRCPv2-Agent-1] [1;0]
    2012-10-12 13:28:33:103028 [INFO]   Remove Control Channel <f3cfe720145f11e2@speechrecog> [0]
    2012-10-12 13:28:33:103032 [DEBUG]  Destroy Container for Pending Control Channels
    2012-10-12 13:28:33:103048 [DEBUG]  Mark Connection for Removal 109.226.9.188:1544 <-> 109.226.9.188:49288
    2012-10-12 13:28:33:103052 [DEBUG]  Signal Message to [MRCP Server] [2;2]
    2012-10-12 13:28:33:103057 [DEBUG]  Wait for Messages [MRCPv2-Agent-1]
    2012-10-12 13:28:33:103099 [DEBUG]  Process Message [MRCP Server] [2;2]
    2012-10-12 13:28:33:103105 [DEBUG]  Control Channel Removed 0x1d590eb8 <f3cfe720145f11e2@speechrecog>
    2012-10-12 13:28:33:103108 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:33:103812 [DEBUG]  Signal Message to [MRCP Server] [3;3]
    2012-10-12 13:28:33:103866 [DEBUG]  Process Message [MRCP Server] [3;3]
    2012-10-12 13:28:33:103875 [DEBUG]  Engine Channel Closed 0x1d590eb8 <f3cfe720145f11e2@speechrecog>
    2012-10-12 13:28:33:103879 [DEBUG]  Wait for Messages [MRCP Server]
    2012-10-12 13:28:33:104637 [DEBUG]  Process Message [Media-Engine-1] [1;0]
    2012-10-12 13:28:33:104648 [DEBUG]  Destroy Audio Bridge 0x1d590eb8
    2012-10-12 13:28:33:104653 [INFO]   Close RTP Receiver 109.226.9.188:5000 <- 109.226.9.188:4002 [r:14 l:0 j:333 d:0 i:0]
    2012-10-12 13:28:33:104660 [DEBUG]  Remove Media Context 0x1d590eb8
    2012-10-12 13:28:33:104664 [INFO]   Remove RTP Session 109.226.9.188:5000
    2012-10-12 13:28:33:104720 [DEBUG]  Process Message [MRCP Server] [4;0]
    2012-10-12 13:28:33:104726 [DEBUG]  Media Termination Subtracted 0x1d590eb8 <f3cfe720145f11e2@media-tm>
    2012-10-12 13:28:33:104729 [DEBUG]  Media Termination Subtracted 0x1d590eb8 <f3cfe720145f11e2@rtp-tm>
    2012-10-12 13:28:33:104733 [NOTICE] Destroy TCP/MRCPv2 Connection 109.226.9.188:1544 <-> 109.226.9.188:49288
    2012-10-12 13:28:33:104742 [INFO]   Session Terminated 0x1d590eb8 <f3cfe720145f11e2>
    2012-10-12 13:28:33:104756 [NOTICE] Destroy Session <f3cfe720145f11e2>
    2012-10-12 13:28:33:104761 [DEBUG]  Wait for Messages [MRCP Server]
    
     
  • Nickolay V. Shmyrev

    Maybe you need to configure voice activity detection in unimrcp (documentation covers that). One possible reason of the broken voice activity detection might be that the audio format you feed into extension is not the one expected. Another reason might be asterisk and unimrcp version incompatibility.

    You can dump audio which is sent to pocketsphinx in order to debug the problem.

     
  • hagai sela

    hagai sela - 2012-10-14

    Hi,
    I have asterisk 1.8.16.0 and unimrcp 1.0.0. I read a little and it seems like there is a compatibility problem with asterisk 1.8.x. Can anyone confirm this?

     
  • hagai sela

    hagai sela - 2012-10-14

    Hi,
    I tried using asterisk 1.6.2.9 instead and results are better. I still have a few problems:
    1. Accuracy is still worse than in the pocketsphinx command line.
    2. I get this warning message from unimrcp:
    [Oct 14 16:30:27] WARNING[9739] res_speech_unimrcp.c: Unsuccessful completion cause:3 reason:none
    Maybe this one should go to the unimrcp forum.
    3. There is too much idle time from the time the voice ends to the recognition results. I tried reducing the timeouts but that didn't seem to work.

    Attached are logs and my acoustic model.
    https://docs.google.com/open?id=0B91Vmp4A3YOuSGRGMnU3RWgzYkU

     
  • hagai sela

    hagai sela - 2012-10-14

    Hi,
    I tried using asterisk 1.6.2.9 instead and results are better. I still have a few problems:
    1. Accuracy is still worse than in the pocketsphinx command line.
    2. I get this warning message from unimrcp:
    [Oct 14 16:30:27] WARNING[9739] res_speech_unimrcp.c: Unsuccessful completion cause:3 reason:none
    Maybe this one should go to the unimrcp forum.
    3. There is too much idle time from the time the voice ends to the recognition results. I tried reducing the timeouts but that didn't seem to work.

    Attached are logs and my acoustic model.
    https://docs.google.com/open?id=0B91Vmp4A3YOuSGRGMnU3RWgzYkU

     
  • hagai sela

    hagai sela - 2012-10-16

    I noticed something strange in the unimrcp server logs: It detects voice activity before I start speaking and then after 300 ms detects voice inactivity. I thought this may be due to cross-talk from the prompt so I changed the prompt to a beep but that didn't help. What am I doing wrong?

     
  • hagai sela

    hagai sela - 2012-10-16

    I solved the timeout problem by recompiling the energy detector code inside unimrcp and setting activity-timeout and inactivity-timeout in pocketsphinx.xml instead of just "timeout".
    The only problem I have now is accuracy. It's the same for pocketsphinx_batch and unimrcp and it's not accurate. I have a working sphinx4 program which is much more accurate.
    I guess I need help with pocketsphinx settings.

     
  • Nickolay V. Shmyrev

    In order to analyze accuracy issues you need to dump the audio you are trying to recognize to files and try to recognize them with pocketsphinx_batch. Then you can reliably compare rates.

    Among options which unimrcp uses, frate 50 is not the best choice.

     
  • hagai sela

    hagai sela - 2012-10-17

    You already helped me once to tune accuracy for the same audio for sphinx 4. file attached.
    Training data also attached.

    https://docs.google.com/open?id=0B91Vmp4A3YOuZW1GbU0ycXl2TTg

    Are there any pointers you can give me on how to tune this myself? I don't want to bother you every time I need to tune for new data.

     
  • hagai sela

    hagai sela - 2012-10-17

    I am running train.bat for adaptation, the pocketsphinx_batch command line is there.

     
  • Nickolay V. Shmyrev

    The issue is to dump the original audio from the asterisk and unimrcp to test the recognition accuracy with offline recognizer. Not the audio you used for adaptation previously.

     
  • hagai sela

    hagai sela - 2012-10-17

    I don't have much audio from there, only recordings of my own voice.
    I tried using the recordings from asterisk with my sphinx4 program and the sphinx 4 program worked great. Since my sphinx 4 program was tuned according to the audio I sent you I thought this should also work.
    I am also attaching the recordings I have from the asterisk machine.

    https://docs.google.com/open?id=0B91Vmp4A3YOuZXNWQ1FIYlR3VEE

     
  • Nickolay V. Shmyrev

    Ok, and what is pocketsphinx_batch accuracy on that data? Is it bad?

    Looking on the samples I see that the detector still doesn't work properly. Please check detector timeout settings. Please note that they changed in unirmcp recently and might cause trouble.

     
  • hagai sela

    hagai sela - 2012-10-18

    pocketsphinx_batch's accuracy on the data is about the same as unimrcp's. It sometimes adds false words and sometimes misrecognizes.
    I used 500 as the detector timeout, is that OK?
    I am using unimrcp 1.0.0 (the version in the uni-ast-package 0.3.2), not the trunk version so I don't think recent changes to the detector should affect my results.

     
    • Nickolay V. Shmyrev

      I wouldn't worry about timeout value. Something is wrong in the voice activity detection and utterances recoreded are clearly wrong. It does not depend on timeout, it's a flaw in the algorithm. It's not really a pocketsphinx problem.

      You might want to debug unirmcp to find a root cause.

       
  • hagai sela

    hagai sela - 2012-10-29

    Hi,
    I debugged unimrcp's pocketsphinx plugin code and played with the timeout settings and the voice activity detector seems to fire at the correct time. I am still getting inaccurate results.
    How could you tell from the audio I sent you that it's a voice activity detector problem? The plugin code doesn't wait for the voice start event to fire before saving the audio, it just saves everything it gets.
    I am also getting the same inaccurate results using pocketsphinx_batch, so this makes me think my problem is not related to unimrcp. Correct me if I am wrong...

     
  • Nickolay V. Shmyrev

    How could you tell from the audio I sent you that it's a voice activity detector problem?

    The recorded audio doesn't contain the word itself, it contains silence. So the voice activity detector didn't cut it properly.

    The plugin code doesn't wait for the voice start event to fire before saving the audio, it just saves everything it gets.

    Yes, this is a problem. It should only process after the the voice start, not the whole thing

     
  • hagai sela

    hagai sela - 2012-10-30

    I fixed this in unimrcp. now I feed audio into pocketsphinx only after voice activity has started.
    I am still getting inaccurate results. The attached audio is recognized as ACHAT SHTAYIM SHALOSH ARBA CHAMESH ACHAT instead of ACHAT SHTAYIM SHALOSH ARBA CHAMESH.

    https://docs.google.com/open?id=0B91Vmp4A3YOucnU4R2lkaXBlUjA

     
    • Nickolay V. Shmyrev

      Great, what was the problem with unimrcp?

      As for not exactly the accurate result, make sure you are not using -frate 50 in client as I wrote above.

       
  • hagai sela

    hagai sela - 2012-10-30

    The problem was as you said - unimrcp feeds all audio to pocketsphinx and doesn't wait for voice activity detection to start.
    Should I use another frate value or remove it?

     
  • hagai sela

    hagai sela - 2012-11-01

    unimrcp also had another problem - it didn't cut the silence at the end of the audio (until voice activity detection fires an inactivity event). I fixed that, but I am still getting inaccurate results while getting accurate results on the same audio in my sphinx4 program.
    an example:

    https://docs.google.com/open?id=0B91Vmp4A3YOuVU9ON0VXTmNVeTQ

    This is recognized as EFES ACHAT SHMONNE SHALOSH TESHA ACHAT SHEVA SHEVA instead of EFES SHALOSH ACHAT SHMONNE SHALOSH EFES ACHAT SHEVA SHEVA.

     

Log in to post a comment.

Want the latest updates on software, tech news, and AI?
Get latest updates about software, tech news, and AI from SourceForge directly in your inbox once a month.