Posted : Tuesday 10/25/2011 11:57 PM
I was dictating into Notepad, using DMPE, Best Match III, on my Core i7 920, @
2.67 GHz, with 12 GB RAM, 8 MB Smart Cache (L3 Cache), Windows 7 64-
bit, with a BOOM O mic, and Andrea soundcard, and had a 1 minute, 2
second latency while dictating (without any misrecognition errors):
Paroxysmal supraventricular tachycardia, 2-3 basal cell carcinomas removed,
hypercholesterolemia, anxiety, stress, insomnia
between the words "removed," and "hypercholesterolemia" without any pause
in dictation on my part.
Notepad | Tue 2011-10-25 | 21:06:35.634 | D | two hyphen three basal cell
carcinomas removed comma
Notepad | Tue 2011-10-25 | 21:07:37.354 | D | hypercholesterolemia
comma
I have a copy of the Recognition History, the Saved Recognition History, the
Saved Recognition History With Details, and the Dragon Log excerpt during that
time--See attached. It documents a 1 minute, 2 second pause between
recognitions in the Recognition History. Someone who is familiar with interpreting
the "Details" of the Recognition History may want to comment on this. If sN is
signal to Noise Ratio, then the details would say in mid sentence I went fron a
SNR of 25 and 24 to 15 and 16. However, maybe the sN is not representative of
this. Also, maybe this reflects that I was also unable to turn the microphone off,
even manually, during this episode.
Then in the Dragon log during this time, I found this particularly interesting, and
maybe at the root of explaining the latency problems:
21:06:36 LOG (Perf): DgnSAPI paused -> BeginUtt = 75 msec
21:06:37 Timeout waiting for COMObjects to be removed from thread
1358.
21:07:37 Timeout waiting for COMObjects to be removed from thread
1358.
21:07:37 Warning: recognition taking too long, aborting it
21:07:37 WARNING (EngSink): The recognizer has encountered an
utterance that is too long to process.
21:07:37
21:07:37 Recognition will continue with the next utterance.
OK, Lindsay, Rudiger, Chuck, Lunis etc--what does this all tell us about
the cause of latency with DMPE (and possibly other flavors of versions 11
and 11.5) ???
NUANCE--PLEASE PAY ATTENTION TO THIS IMPORTANT
INFO!!!
RECOGNITION HISTORY DURING 1 MINUTE LATENCY:
RECOGNITION HISTORY SAVED WITH DETAILS DURING 1 MINUTE LATENCY:
0.0 [ 6363] | sA 27.4 [ 6362] | C | switch to Notepad
Notepad | Tue 2011-10-25 | 21:06:31.434 | uD 3267 | Nd 0 | sN 25 | cD 20 |
wF 0x00 | aF 0x00 | dA 0.0 [ 9630] | sA 26.6 [ 9629] | D | paroxysmal
supraventricular tachycardia comma
Notepad | Tue 2011-10-25 | 21:06:35.634 | uD 3858 | Nd 0 | sN 24 | cD 30 |
wF 0x00 | aF 0x00 | dA 0.0 [13488] | sA 25.9 [13487] | D | two hyphen three
basal cell carcinomas removed comma
Notepad | Tue 2011-10-25 | 21:07:37.354 | uD 1783 | Nd 0 | sN 15 | cD 20 |
wF 0x00 | aF 0x00 | dA 0.0 [15271] | sA 24.6 [15270] | D |
hypercholesterolemia comma
Notepad | Tue 2011-10-25 | 21:07:38.204 | uD 3116 | Nd 0 | sN 16 | cD 0 | wF
0x00 | aF 0x00 | dA 0.0 [18387] | sA 23.1 [18386] | D | anxiety comma stress
comma insomnia
RECOGNITION HISTORY SAVED WITHOUT DETAILS DURING 1 MINUTE
LATENCY:
WFICA32 | Tue 2011-10-25 | 21:06:28.044 | C | switch to Notepad
Notepad | Tue 2011-10-25 | 21:06:31.434 | D | paroxysmal supraventricular
tachycardia comma
Notepad | Tue 2011-10-25 | 21:06:35.634 | D | two hyphen three basal cell
carcinomas removed comma
Notepad | Tue 2011-10-25 | 21:07:37.354 | D | hypercholesterolemia comma
Notepad | Tue 2011-10-25 | 21:07:38.204 | D | anxiety comma stress comma
insomnia
DRAGON LOG EXCERPT DURING 1 MINUTE LATENCY:
21:06:31 SigQual[ uD 3267 | Nd 0 | sN 25 | cD 20 | wF 0x00 | aF 0x00 | dA 0.0
[9630] | sA 26.6 [9629] | Rt D ]
21:06:31 LOG (Perf): DgnSAPI paused -> BeginUtt = 75 msec
21:06:35 SigQual[ uD 3858 | Nd 0 | sN 24 | cD 30 | wF 0x00 | aF 0x00 | dA 0.0
[13488] | sA 25.9 [13487] | Rt D ]
21:06:36 LOG (Perf): DgnSAPI paused -> BeginUtt = 75 msec
21:06:37 Timeout waiting for COMObjects to be removed from thread 1358.
21:07:37 Timeout waiting for COMObjects to be removed from thread 1358.
21:07:37 Warning: recognition taking too long, aborting it
21:07:37 WARNING (EngSink): The recognizer has encountered an utterance
that is too long to process.
21:07:37
21:07:37 Recognition will continue with the next utterance.
21:07:37 SigQual[ uD 1783 | Nd 0 | sN 15 | cD 20 | wF 0x00 | aF 0x00 | dA 0.0
[15271] | sA 24.6 [15270] | Rt D ]
21:07:37 LOG (Perf): DgnSAPI paused -> BeginUtt = 271 msec
21:07:38 SigQual[ uD 3116 | Nd 0 | sN 16 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt D ]
21:07:38 LOG (Perf): DgnSAPI paused -> BeginUtt = 70 msec
21:07:39 SigQual[ uD 952 | Nd 0 | sN 16 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt R ]x
21:07:39 Info: turning off microphone immediate
21:07:39 Info: multimedia device ID 0 name
FULL DRAGON LOG:
21:05:52 Info: opening file
21:05:52 LOG (Perf): Selecting topic based on US English | Large | Internal
Medicine (ID=1024)
21:05:52 LOG (Perf): Selecting user based on US English | BestMatch III |
General Medical (ID=10610)
21:05:52 LOG (VBar): User
'C:\ProgramData\Nuance\NaturallySpeaking11\Users\MARK SCV IM BM III (1)' is
LOCAL
21:05:52 Roaming: roamingUserCurrentUserIsRoaming = 0
21:05:52 Info: opening file
21:05:52 Overriding server parameter "DoVocDeltaFile" to "1"
21:05:52 Info: received closed callback
21:05:52 Info: speaker
21:05:52 Info: topic
21:05:52 Info: acoustic
21:05:52 Info: flags usr 0 sig 0 usrbase 0 usigbase 0
21:05:52 Info: Speaker open
21:05:52 Info: Opening user file
C:\ProgramData\Nuance\NaturallySpeaking11\Users\MARK SCV IM BM III
(1)\current\voice\enu_med_11k_p1.usr
21:05:52 Info: Opening sig file
C:\ProgramData\Nuance\NaturallySpeaking11\Users\MARK SCV IM BM III
(1)\current\voice\enu_med_11k_p1.sig
21:05:52 Info: base model is
21:05:52 Info: internal base model is
21:05:52 Info: training status, Warping 1 count 0 length 0
21:05:52 Info: overrides file
21:05:52 Warning: Found duplicate key
'SearchRemoveInactiveWordsIntervalFrames' in section 'Recognizer Overrides'
of preference file
'C:\ProgramData\Nuance\NaturallySpeaking11\Data\enu\ini\enu_med_p1.ini'.
Ignoring duplicate.
21:05:52 Overriding server parameter "DwSpeechThreshold" to "20"
21:05:52 Overriding server parameter "ComputeSpeed" to "100"
21:05:52 Overriding server parameter "UseBackupDictInWords" to "0"
21:05:52 Overriding server parameter "DwTimeOutIncomplete" to "160"
21:05:52 Overriding server parameter "DwTimeOutComplete" to "100"
21:05:52 Overriding server parameter "WAVFileMax" to "100000"
21:05:52 Overriding server parameter "SaveWAVToDisk" to "1"
21:05:52 Overriding server parameter "DoDataCollection" to "0"
21:05:52 Info: opening file
21:05:52 Opening Topic
C:\ProgramData\Nuance\NaturallySpeaking11\Users\MARK SCV IM BM III
(1)\current\Internal
21:05:52 Using static Vocabulary
C:\ProgramData\Nuance\NaturallySpeaking11\Data\enu\lm\dns\medical\gener
alpractice\general.svc
21:05:52 Info: svc preload size 78643200
21:05:54 Info: load voc time 1939
21:05:54 Info: topic slot found
21:05:54 Info: topic slot , no data
21:05:54 Info: topic slot , no data
21:05:54 Info: topic slot found
21:05:54 Info: Mrec version of voc
21:05:54 Info: VocVersionID
21:05:54 Info: building number mode reject rule
21:05:54 Info: start time prefilterer rebuild 56873877
21:05:55 Info: end time prefilterer rebuild 56874033
21:05:55 Info: opening lexicon
21:05:55 Tokenizer: Lexicon VocVersionID: natspeak/eng-
USA/generalpractice/large/2011_05_28/20110528125009
21:05:55 Tokenizer: Lexicon TokenPhilosophyVersion: 2
21:05:55 Tokenizer: Lexicon LanguageCode: eng
21:05:55 Info: opening TKN
21:05:55 Info: VetoMoreWordFlags set to
21:05:55 Info: aging max words 615168
21:05:55 Info: aging rounded maxwords 615168
21:05:55 Info: maximum aging words 615168
21:05:55 Info: dictation rule allows silence
21:05:55 Info: opening ITN
21:05:55 Info: Dictation mode is interactive
21:05:55 Warning: missing POS file
21:05:55 Info: base topic is
21:05:55 Info: internal base topic is
21:05:55 Info: trying to load confidence file for US English, US English |
BestMatch III | General Medical, US English | Large | Internal Medicine
21:05:55 Info: loading confidence file
21:05:55 Info: overrides file
21:05:55 load computespeed file
C:\ProgramData\Nuance\NaturallySpeaking11\Data\enu\ini\computespeed_en
u_med_p1.ini
21:05:55 Info: end of load from computespeed file
21:05:55 Info: SpeechThreshold 20
21:05:55 Info: restoreArchivedGrammars
21:05:55 Info: unarchiveITNResults
21:05:55 Info: updating memory abort setting to 2000000000, was 402653184
21:05:55 Info: running init recognition from
21:05:55 Info: computespeed 100
21:05:55 Info: no prefilterer interns set
21:05:58 Info: multimedia device ID 0 name
21:05:58 Info: Save User and GUID to Speaker
21:05:58 LOG (Perf): Time to load ITN options from S2 = 294 msec
21:05:58 LOG (Perf): Time to load ITN options from file = 456 msec
21:05:58 LOG (Perf): User and topic select = 6448 msec
21:05:58 LOG (VBar) Begin cleanupAcOptSessionArchive
21:05:58 ClsDragonBar::updateModesMenu( 40062 ) 0 Recognition is in Normal
Mode
21:05:58 ACO: Info:
ClsNISTWavFile::open(, mode=32)
successful.
21:05:58 ACO: Info:
ClsNISTWavFile::close()
21:05:58 ACO: Info:
ClsNISTWavFile::open(, mode=32)
successful.
21:05:58 ACO: Info:
ClsNISTWavFile::open(, mode=4113) successful.
21:05:58 ClsDragonBar::updateModesMenu( 40062 ) 0 Recognition is in Normal
Mode
21:05:58 ACO: Info:
ClsNISTWavFile::close()
21:05:58 ACO: Info:
ClsNISTWavFile::close()
21:05:58 ACO: Info:
ClsNISTWavFile::open(, mode=32) successful.
21:05:58 ACO: Info:
ClsNISTWavFile::close()
21:05:58 ACO: Info:
ClsNISTWavFile::open(, mode=8226) successful.
21:05:58 ACO: Info:
ClsNISTWavFile::open(, mode=4113)
successful.
21:05:59 ACO: Info:
ClsNISTWavFile::close()
21:05:59 ACO: Info:
ClsNISTWavFile::close()
21:05:59 LOG (VBar) End cleanupAcOptSessionArchive
21:05:59 LOG (Perf): Cleanup acoustic archive = 295 msec
21:05:59 LOG (Perf): Loading compatibility modules...
21:05:59 Info: SpeechThreshold 20
21:05:59 Info: SpeechThreshold 20
21:05:59 Info: SpeechThreshold 20
21:05:59 Info: SpeechThreshold 20
21:05:59 Info: SpeechThreshold 20
21:05:59 NATSPEAK: DGNCOMPMNGR is initialized.
21:05:59 RGY variable 'Wave Data Always Preserved' = 1
21:05:59 RGY variable 'Transfer With Speech' = 0
21:05:59 RGY variable 'Preserve Audio In Empty Document' = 0
21:05:59 RGY variable 'Overdictate Preserved Speech' = 0
21:05:59 RGY variable 'Greedy Replacement Option' = 1
21:05:59 RGY variable 'Serial Insert Option' = 0
21:05:59 Initializing VDCT with ITN options...
21:05:59 [x64] (SDK-redirection) Connected to ActiveServices from IL=3
PID=0xA5C
21:05:59 VDCT retrieveITNParams: VDCT uses locale m_lcid =1033
21:05:59 LOG (Perf): Time to init VDCT with ITN options = 2 msec
21:05:59 NumFmt, In locale: United States
21:05:59 NumFmt, Sample number format: -12,345.6
21:05:59 NumFmt, Sample currency format: $10,000.05
21:05:59 Info: building new number mode rule
21:05:59 LOG (Perf): DgnMicBtn::Register() = 0 msec
21:05:59 LOG (Perf): Time to track desktop = 35 msec
21:05:59 LOG (Perf): Time to track start menu = 25 msec
21:05:59 (MyCmds) MyCommands initialized for "MARK SCV IM BM III (1)"
speaker with 0x409 language
21:05:59 EditControl compatibility module launched.
21:05:59 LOG (Perf): Time to track common start menu = 294 msec
21:05:59 LOG (Perf): Time to track common desktop = 0 msec
21:05:59 LOG (Perf): Time to track my documents = 0 msec
21:05:59 LOG (Perf): Time to track desktop apps = 398 msec
21:06:00 (MyCmds) MyCommands snap-shot generated
21:06:00 NaturalText v.11.00.300.312 compatibility module launched.
21:06:01 LOG (Perf): Time to add CM support for {dd100203-6205-11cf-ae61-
0000e8a28647} = 621 msec
21:06:01 LOG (Perf): Loading of compatibility modules took 1944 msec
21:06:01 VDCT retrieveITNParams: VDCT uses locale m_lcid =1033
21:06:01 VDCT retrieveITNParams: VDCT uses locale m_lcid =1033
21:06:01 VDCT retrieveITNParams: VDCT uses locale m_lcid =1033
21:06:01 ClsDragonBar::updateModesMenu( 40062 ) 0 Recognition is in Normal
Mode
21:06:01 LOG (DragonBar): Archive size + dra size (seconds) = 558
21:06:04 Info: multimedia device ID 0 name
21:06:04 Info: default live mic sample rate is 22050
21:06:04 Info: live mic sample rate 22050
21:06:05 Info: using word pairs
21:06:05 Warning: foreground window NULL in recog
21:06:05 LOG (Perf): DgnSAPI paused -> BeginUtt = 184 msec
21:06:07 SigQual[ uD 1132 | Nd 0 | sN 15 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0 [0]
| sA 0.0 [0] | Rt R ]x
21:06:08 LOG (Perf): DgnSAPI paused -> BeginUtt = 84 msec
21:06:09 Warning: skipping OUFA, missing wordspec for word
21:06:09 SigQual[ uD 1703 | Nd 0 | sN 27 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[1703] | sA 27.0 [1703] | Rt C ]
21:06:12 LOG (Perf): DgnSAPI paused -> BeginUtt = 96 msec
21:06:13 Info: skipping utt for OUFA, low SNR
21:06:13 SigQual[ uD 1172 | Nd 0 | sN 10 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[1703] | sA 27.0 [1703] | Rt R ]x
21:06:13 LOG (Perf): DgnSAPI paused -> BeginUtt = 72 msec
21:06:15 Warning: skipping OUFA, missing wordspec for word
21:06:15 SigQual[ uD 1573 | Nd 0 | sN 26 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[3276] | sA 26.5 [3276] | Rt C ]
21:06:16 Scripting::ExecuteScript script 'SetMousePosition 1, 875, 299' failed
(0x0)
21:06:16 Scripting::ExecuteScript script 'ButtonClick 1, 1' failed (0x0)
21:06:16 Scripting::ExecuteScript script 'HeardWord "\Cap"' failed (0x0)
21:06:16 in: out:
21:06:16 in: out:
21:06:16 in: out:
21:06:16 in: out:
21:06:16 LOG (Perf): DgnSAPI paused -> BeginUtt = 80 msec
21:06:16 S2 returned error DSXError_NotEnoughData in file
E:\Work\med11emea\dgnsapi\portres.cpp, line 3118
21:06:16 SigQual[ uD 1 | Nd 0 | sN -1 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0 [3277]
| sA 26.5 [3276] | Rt D ]
21:06:22 LOG (Perf): DgnSAPI paused -> BeginUtt = 86 msec
21:06:24 Warning: skipping OUFA, missing wordspec for word
21:06:24 SigQual[ uD 1473 | Nd 0 | sN 30 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[4750] | sA 27.6 [4749] | Rt C ]
21:06:24 Scripting::ExecuteScript script 'SetMousePosition 1, 836, 256' failed
(0x0)
21:06:25 Scripting::ExecuteScript script 'ButtonClick 1, 1' failed (0x0)
21:06:25 LOG (Perf): DgnSAPI paused -> BeginUtt = 87 msec
21:06:28 SigQual[ uD 1613 | Nd 0 | sN 27 | cD 30 | wF 0x00 | aF 0x00 | dA 0.0
[6363] | sA 27.4 [6362] | Rt C ]
21:06:28 LOG (Perf): DgnSAPI paused -> BeginUtt = 85 msec
21:06:31 SigQual[ uD 3267 | Nd 0 | sN 25 | cD 20 | wF 0x00 | aF 0x00 | dA 0.0
[9630] | sA 26.6 [9629] | Rt D ]
21:06:31 LOG (Perf): DgnSAPI paused -> BeginUtt = 75 msec
21:06:35 SigQual[ uD 3858 | Nd 0 | sN 24 | cD 30 | wF 0x00 | aF 0x00 | dA 0.0
[13488] | sA 25.9 [13487] | Rt D ]
21:06:36 LOG (Perf): DgnSAPI paused -> BeginUtt = 75 msec
21:06:37 Timeout waiting for COMObjects to be removed from thread 1358.
21:07:37 Timeout waiting for COMObjects to be removed from thread 1358.
21:07:37 Warning: recognition taking too long, aborting it
21:07:37 WARNING (EngSink): The recognizer has encountered an utterance
that is too long to process.
21:07:37
21:07:37 Recognition will continue with the next utterance.
21:07:37 SigQual[ uD 1783 | Nd 0 | sN 15 | cD 20 | wF 0x00 | aF 0x00 | dA 0.0
[15271] | sA 24.6 [15270] | Rt D ]
21:07:37 LOG (Perf): DgnSAPI paused -> BeginUtt = 271 msec
21:07:38 SigQual[ uD 3116 | Nd 0 | sN 16 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt D ]
21:07:38 LOG (Perf): DgnSAPI paused -> BeginUtt = 70 msec
21:07:39 SigQual[ uD 952 | Nd 0 | sN 16 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt R ]x
21:07:39 Info: turning off microphone immediate
21:07:39 Info: multimedia device ID 0 name
21:07:39 LOG (Perf): DgnSAPI paused -> BeginUtt = 75 msec
21:07:41 Info: skipping utt for OUFA, low SNR
21:07:41 SigQual[ uD 1212 | Nd 0 | sN 9 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt R ]x
21:07:41 Info: turning off microphone immediate
21:07:41 Info: multimedia device ID 0 name
21:07:41 Info: turning off microphone immediate
21:07:41 LOG (Perf): DgnSAPI paused -> BeginUtt = 96 msec
21:07:42 Info: multimedia device ID 0 name
21:07:42 SigQual[ uD 1312 | Nd 0 | sN 16 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt R ]x
21:07:42 Info: turning off microphone immediate
21:07:43 Info: multimedia device ID 0 name
21:07:43 Info: turning off microphone immediate
21:07:43 LOG (Perf): DgnSAPI paused -> BeginUtt = 85 msec
21:07:44 Info: multimedia device ID 0 name
21:07:44 SigQual[ uD 1142 | Nd 0 | sN 16 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt R ]x
21:07:44 Info: turning off microphone immediate
21:07:44 Info: multimedia device ID 0 name
21:07:44 Info: turning off microphone immediate
21:07:44 LOG (Perf): DgnSAPI paused -> BeginUtt = 81 msec
21:07:46 Info: skipping utt for OUFA, low SNR
21:07:46 Info: multimedia device ID 0 name
21:07:46 SigQual[ uD 1222 | Nd 0 | sN 13 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt R ]x
21:07:46 Info: turning off microphone immediate
21:07:46 Info: multimedia device ID 0 name
21:07:46 Info: turning off microphone immediate
21:07:46 LOG (Perf): DgnSAPI paused -> BeginUtt = 76 msec
21:07:48 Info: skipping utt for OUFA, low SNR
21:07:48 Info: multimedia device ID 0 name
21:07:48 SigQual[ uD 1292 | Nd 0 | sN 13 | cD 0 | wF 0x00 | aF 0x00 | dA 0.0
[18387] | sA 23.1 [18386] | Rt R ]x
21:07:48 Info: turning off microphone immediate