zh794390558 / paddle_build

3 stars 2 forks source link

inference profiling #7

Open zh794390558 opened 2 years ago

zh794390558 commented 2 years ago

现在的profile,看不到OP的统计信息,分析起来不方便,可以直接用inference里面的profile, 先在Paddle/paddle/fluid/jit/engine/predictor_engine.h中增加如下配置:

4ce85b6abeeba4423b908a66555729e8

然后paddle_build/test/u2/decoder_main.cc中关闭USE_PROFILING宏。 然后运行时就会有如下的统计信息: ac533ae286247b72babf05dac96c23bc

zh794390558 commented 2 years ago

paddle_build u2++跑出来的timeline

I1026 08:59:03.499194 41684 asr_decoder.cc:233] Attention Rescoring takes 251
I1026 08:59:03.690184 41684 asr_decoder.cc:119] forward takes 155 ms, search takes 9 ms
I1026 08:59:03.858732 41684 asr_decoder.cc:119] forward takes 157 ms, search takes 10 ms
I1026 08:59:04.031708 41684 asr_decoder.cc:119] forward takes 162 ms, search takes 10 ms
I1026 08:59:04.209312 41684 asr_decoder.cc:119] forward takes 166 ms, search takes 10 ms
I1026 08:59:04.391198 41684 asr_decoder.cc:119] forward takes 170 ms, search takes 10 ms
I1026 08:59:04.574836 41684 asr_decoder.cc:119] forward takes 172 ms, search takes 11 ms
I1026 08:59:04.722481 41684 asr_decoder.cc:119] forward takes 142 ms, search takes 5 ms
I1026 08:59:05.007769 41684 asr_decoder.cc:233] Attention Rescoring takes 284
I1026 08:59:05.197088 41684 asr_decoder.cc:119] forward takes 156 ms, search takes 9 ms
I1026 08:59:05.364830 41684 asr_decoder.cc:119] forward takes 157 ms, search takes 10 ms
I1026 08:59:05.538614 41684 asr_decoder.cc:119] forward takes 162 ms, search takes 10 ms
I1026 08:59:05.715237 41684 asr_decoder.cc:119] forward takes 165 ms, search takes 11 ms
I1026 08:59:05.896705 41684 asr_decoder.cc:119] forward takes 170 ms, search takes 11 ms
I1026 08:59:06.085235 41684 asr_decoder.cc:119] forward takes 177 ms, search takes 11 ms
I1026 08:59:06.085332 41684 asr_decoder.cc:119] forward takes 0 ms, search takes 0 ms
I1026 08:59:06.346666 41684 asr_decoder.cc:233] Attention Rescoring takes 260
I1026 08:59:06.541410 41684 asr_decoder.cc:119] forward takes 155 ms, search takes 9 ms
I1026 08:59:06.707963 41684 asr_decoder.cc:119] forward takes 155 ms, search takes 10 ms
I1026 08:59:06.880982 41684 asr_decoder.cc:119] forward takes 162 ms, search takes 10 ms
I1026 08:59:07.056469 41684 asr_decoder.cc:119] forward takes 164 ms, search takes 10 ms
I1026 08:59:07.238682 41684 asr_decoder.cc:119] forward takes 171 ms, search takes 11 ms
I1026 08:59:07.423346 41684 asr_decoder.cc:119] forward takes 173 ms, search takes 11 ms
I1026 08:59:07.612200 41684 asr_decoder.cc:119] forward takes 177 ms, search takes 11 ms
I1026 08:59:07.849066 41684 asr_decoder.cc:119] forward takes 228 ms, search takes 8 ms
I1026 08:59:08.219203 41684 asr_decoder.cc:233] Attention Rescoring takes 369
I1026 08:59:08.407586 41684 asr_decoder.cc:119] forward takes 156 ms, search takes 10 ms
I1026 08:59:08.577908 41684 asr_decoder.cc:119] forward takes 159 ms, search takes 10 ms
I1026 08:59:08.750523 41684 asr_decoder.cc:119] forward takes 161 ms, search takes 10 ms
I1026 08:59:08.928035 41684 asr_decoder.cc:119] forward takes 166 ms, search takes 10 ms
I1026 08:59:09.109799 41684 asr_decoder.cc:119] forward takes 170 ms, search takes 11 ms
I1026 08:59:09.319829 41684 asr_decoder.cc:119] forward takes 203 ms, search takes 6 ms
I1026 08:59:09.556288 41684 asr_decoder.cc:233] Attention Rescoring takes 235
I1026 08:59:09.742930 41684 asr_decoder.cc:119] forward takes 155 ms, search takes 10 ms
I1026 08:59:09.909690 41684 asr_decoder.cc:119] forward takes 156 ms, search takes 10 ms
I1026 08:59:10.081749 41684 asr_decoder.cc:119] forward takes 161 ms, search takes 10 ms
I1026 08:59:10.256844 41684 asr_decoder.cc:119] forward takes 164 ms, search takes 10 ms
I1026 08:59:10.438688 41684 asr_decoder.cc:119] forward takes 170 ms, search takes 10 ms
I1026 08:59:10.588306 41684 asr_decoder.cc:119] forward takes 143 ms, search takes 5 ms
I1026 08:59:10.809806 41684 asr_decoder.cc:233] Attention Rescoring takes 220
I1026 08:59:10.994871 41684 asr_decoder.cc:119] forward takes 155 ms, search takes 9 ms
I1026 08:59:11.162209 41684 asr_decoder.cc:119] forward takes 156 ms, search takes 10 ms
I1026 08:59:11.334537 41684 asr_decoder.cc:119] forward takes 161 ms, search takes 10 ms
I1026 08:59:11.509858 41684 asr_decoder.cc:119] forward takes 164 ms, search takes 10 ms
I1026 08:59:11.691619 41684 asr_decoder.cc:119] forward takes 170 ms, search takes 10 ms
I1026 08:59:11.812292 41684 asr_decoder.cc:119] forward takes 118 ms, search takes 1 ms
I1026 08:59:12.037534 41684 asr_decoder.cc:233] Attention Rescoring takes 224
I1026 08:59:12.241009 41684 asr_decoder.cc:119] forward takes 157 ms, search takes 9 ms
I1026 08:59:12.411813 41684 asr_decoder.cc:119] forward takes 160 ms, search takes 10 ms
I1026 08:59:12.584539 41684 asr_decoder.cc:119] forward takes 161 ms, search takes 10 ms
I1026 08:59:12.764220 41684 asr_decoder.cc:119] forward takes 168 ms, search takes 10 ms
I1026 08:59:12.947002 41684 asr_decoder.cc:119] forward takes 171 ms, search takes 10 ms
I1026 08:59:13.134935 41684 asr_decoder.cc:119] forward takes 176 ms, search takes 11 ms
I1026 08:59:13.325620 41684 asr_decoder.cc:119] forward takes 179 ms, search takes 11 ms
I1026 08:59:13.523922 41684 asr_decoder.cc:119] forward takes 186 ms, search takes 11 ms
I1026 08:59:13.730183 41684 asr_decoder.cc:119] forward takes 194 ms, search takes 11 ms
I1026 08:59:13.923380 41684 asr_decoder.cc:119] forward takes 186 ms, search takes 6 ms
zh794390558 commented 2 years ago

目前看应该是统计时间的方法不统一。 wenet只统计了forward + decode的部分时间,其他时间都不包含。

zh794390558 commented 2 years ago

目前feature pipeline 一次的时间

I1025 09:40:25.199138 24776 audio_cache.cc:52] AudioCache::Accept cost: 0.000102043 sec. 5760 samples.
I1025 09:40:25.199262 24776 audio_cache.cc:94] AudioCache::Read cost: 0.000102997 sec.
I1025 09:40:25.202809 24776 feature_common_inl.h:56] StreamingFeatureTpl<F>::Read cost: 0.00353312 sec.
I1025 09:40:25.202903 24776 cmvn.cc:57] CMVN::Read cost: 7.20024e-05 sec.
I1025 09:40:25.202948 24776 audio_cache.cc:94] AudioCache::Read cost: 3.8147e-06 sec.
I1025 09:40:25.202962 24776 feature_cache.cc:43] FeatureCache::Accept cost: 0.0039289 sec. 5760 samples.
I1025 09:40:25.202971 24776 u2_recognizer.cc:72] feed waves cost: 0.00394106 sec. 5760 samples.
I1025 09:40:25.202992 24776 feature_cache.cc:67] FeatureCache::Read cost: 5.00679e-06 sec.
I1025 09:40:25.203001 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203009 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203016 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203030 24776 feature_cache.cc:67] FeatureCache::Read cost: 1.09673e-05 sec.
I1025 09:40:25.203039 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203066 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.8147e-06 sec.
I1025 09:40:25.203074 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203081 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203088 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203095 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203102 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.8147e-06 sec.
I1025 09:40:25.203109 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203116 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203123 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203131 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203138 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203145 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203161 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203168 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203176 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203182 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203189 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203202 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203210 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203217 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203231 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.8147e-06 sec.
I1025 09:40:25.203238 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.203245 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203258 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203272 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203280 24776 feature_cache.cc:67] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 09:40:25.203292 24776 feature_cache.cc:67] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 09:40:25.203300 24776 feature_cache.cc:67] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 09:40:25.205355 24776 assembler.cc:45] Assembler::Read cost: 0.00237107 sec.
I1025 09:40:25.205381 24776 ctc_prefix_beam_search_decoder.cc:93] AdvanceDecode feat + forward  cost: 0.00238991 sec.
I1025 09:40:25.205389 24776 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
zh794390558 commented 2 years ago

AudioCache::Accept 耗时

I1025 11:12:06.347469 31760 audio_cache.cc:52] AudioCache::Accept cost: 9.98974e-05 sec. 5760 samples.
I1025 11:12:06.353883 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000118017 sec. 5760 samples.
I1025 11:12:06.588995 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000128031 sec. 5760 samples.
I1025 11:12:06.595530 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000118017 sec. 5760 samples.
I1025 11:12:06.859483 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000206947 sec. 5760 samples.
I1025 11:12:06.867794 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000116825 sec. 5760 samples.
I1025 11:12:07.125864 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000114918 sec. 5760 samples.
I1025 11:12:07.132692 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.00011301 sec. 5760 samples.
I1025 11:12:07.393115 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000111818 sec. 5760 samples.
I1025 11:12:07.399482 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000117064 sec. 5760 samples.
I1025 11:12:07.673259 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000117064 sec. 5760 samples.
I1025 11:12:07.955734 31760 audio_cache.cc:52] AudioCache::Accept cost: 8.10623e-05 sec. 3903 samples.
I1025 11:12:08.685426 31760 audio_cache.cc:52] AudioCache::Accept cost: 9.70364e-05 sec. 5760 samples.
I1025 11:12:08.691466 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000116825 sec. 5760 samples.
I1025 11:12:08.925957 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000119925 sec. 5760 samples.
I1025 11:12:08.932492 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000117064 sec. 5760 samples.
I1025 11:12:09.170415 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000113964 sec. 5760 samples.
I1025 11:12:09.176851 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000114918 sec. 5760 samples.
I1025 11:12:09.415704 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000114202 sec. 5760 samples.
I1025 11:12:09.422324 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000117064 sec. 5760 samples.
I1025 11:12:09.664500 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000113964 sec. 5760 samples.
I1025 11:12:09.671305 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000113964 sec. 5760 samples.
I1025 11:12:09.922282 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000113964 sec. 5760 samples.
I1025 11:12:10.178900 31760 audio_cache.cc:52] AudioCache::Accept cost: 5.38826e-05 sec. 2480 samples.
I1025 11:12:10.746974 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.00012517 sec. 5760 samples.
I1025 11:12:10.753198 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000200987 sec. 5760 samples.
I1025 11:12:10.985061 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000124931 sec. 5760 samples.
I1025 11:12:10.991593 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000117064 sec. 5760 samples.
I1025 11:12:11.228122 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000126123 sec. 5760 samples.
I1025 11:12:11.234652 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.00011611 sec. 5760 samples.
I1025 11:12:11.472415 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.00011301 sec. 5760 samples.
I1025 11:12:11.478905 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.00011611 sec. 5760 samples.
I1025 11:12:11.721191 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000113964 sec. 5760 samples.
I1025 11:12:11.727728 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000115871 sec. 5760 samples.
I1025 11:12:11.980998 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000122786 sec. 5760 samples.
I1025 11:12:12.240726 31760 audio_cache.cc:52] AudioCache::Accept cost: 1.90735e-05 sec. 640 samples.
I1025 11:12:12.767675 31760 audio_cache.cc:52] AudioCache::Accept cost: 9.89437e-05 sec. 5760 samples.
I1025 11:12:12.773934 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000123024 sec. 5760 samples.
I1025 11:12:13.006386 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.00011301 sec. 5760 samples.
I1025 11:12:13.012825 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.00011611 sec. 5760 samples.
I1025 11:12:13.249004 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.00010705 sec. 5760 samples.
I1025 11:12:13.255797 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000114918 sec. 5760 samples.
I1025 11:12:13.491752 31760 audio_cache.cc:52] AudioCache::Accept cost: 9.58443e-05 sec. 5760 samples.
I1025 11:12:13.498003 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000120163 sec. 5760 samples.
I1025 11:12:13.740550 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000114918 sec. 5760 samples.
I1025 11:12:13.746958 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000120878 sec. 5760 samples.
zh794390558 commented 2 years ago

AudioCache::Read 耗时

I1025 11:12:06.347585 31760 audio_cache.cc:94] AudioCache::Read cost: 9.5129e-05 sec.
I1025 11:12:06.351351 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.353998 31760 audio_cache.cc:94] AudioCache::Read cost: 0.000102043 sec.
I1025 11:12:06.357787 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:06.589114 31760 audio_cache.cc:94] AudioCache::Read cost: 0.000103951 sec.
I1025 11:12:06.592887 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:06.595634 31760 audio_cache.cc:94] AudioCache::Read cost: 9.29832e-05 sec.
I1025 11:12:06.599337 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.859676 31760 audio_cache.cc:94] AudioCache::Read cost: 0.000139952 sec.
I1025 11:12:06.865131 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.867897 31760 audio_cache.cc:94] AudioCache::Read cost: 9.20296e-05 sec.
I1025 11:12:06.872087 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:07.125980 31760 audio_cache.cc:94] AudioCache::Read cost: 9.98974e-05 sec.
I1025 11:12:07.129951 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:07.132797 31760 audio_cache.cc:94] AudioCache::Read cost: 9.29832e-05 sec.
I1025 11:12:07.136510 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:07.393209 31760 audio_cache.cc:94] AudioCache::Read cost: 7.79629e-05 sec.
I1025 11:12:07.396811 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:07.399585 31760 audio_cache.cc:94] AudioCache::Read cost: 9.20296e-05 sec.
I1025 11:12:07.403275 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:07.673369 31760 audio_cache.cc:94] AudioCache::Read cost: 9.20296e-05 sec.
I1025 11:12:07.677125 31760 audio_cache.cc:94] AudioCache::Read cost: 3.09944e-06 sec.
I1025 11:12:07.955812 31760 audio_cache.cc:94] AudioCache::Read cost: 6.41346e-05 sec.
I1025 11:12:07.958570 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:07.958599 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:08.685519 31760 audio_cache.cc:94] AudioCache::Read cost: 7.79629e-05 sec.
I1025 11:12:08.688881 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:08.691570 31760 audio_cache.cc:94] AudioCache::Read cost: 9.20296e-05 sec.
I1025 11:12:08.695302 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:08.926074 31760 audio_cache.cc:94] AudioCache::Read cost: 0.000101089 sec.
I1025 11:12:08.929849 31760 audio_cache.cc:94] AudioCache::Read cost: 3.09944e-06 sec.
I1025 11:12:08.932593 31760 audio_cache.cc:94] AudioCache::Read cost: 9.20296e-05 sec.
I1025 11:12:08.936288 31760 audio_cache.cc:94] AudioCache::Read cost: 3.8147e-06 sec.
I1025 11:12:09.170519 31760 audio_cache.cc:94] AudioCache::Read cost: 9.29832e-05 sec.
I1025 11:12:09.174225 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:09.176959 31760 audio_cache.cc:94] AudioCache::Read cost: 9.799e-05 sec.
I1025 11:12:09.180724 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:09.415807 31760 audio_cache.cc:94] AudioCache::Read cost: 9.29832e-05 sec.
I1025 11:12:09.419644 31760 audio_cache.cc:94] AudioCache::Read cost: 3.8147e-06 sec.
I1025 11:12:09.422427 31760 audio_cache.cc:94] AudioCache::Read cost: 9.29832e-05 sec.
I1025 11:12:09.426141 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:09.664605 31760 audio_cache.cc:94] AudioCache::Read cost: 9.29832e-05 sec.
I1025 11:12:09.668661 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:09.671407 31760 audio_cache.cc:94] AudioCache::Read cost: 9.20296e-05 sec.
I1025 11:12:09.675149 31760 audio_cache.cc:94] AudioCache::Read cost: 3.09944e-06 sec.
I1025 11:12:09.922385 31760 audio_cache.cc:94] AudioCache::Read cost: 9.29832e-05 sec.
I1025 11:12:09.926154 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:10.178961 31760 audio_cache.cc:94] AudioCache::Read cost: 4.88758e-05 sec.
I1025 11:12:10.180739 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:10.180760 31760 audio_cache.cc:94] AudioCache::Read cost: 3.09944e-06 sec.
I1025 11:12:10.747077 31760 audio_cache.cc:94] AudioCache::Read cost: 8.70228e-05 sec.
I1025 11:12:10.750437 31760 audio_cache.cc:94] AudioCache::Read cost: 3.09944e-06 sec.
I1025 11:12:10.753361 31760 audio_cache.cc:94] AudioCache::Read cost: 0.000133991 sec.
:
zh794390558 commented 2 years ago

AcceptWaveform cost:

I1025 11:12:06.347469 31760 audio_cache.cc:52] AudioCache::Accept cost: 9.98974e-05 sec. 5760 samples.
I1025 11:12:06.347585 31760 audio_cache.cc:94] AudioCache::Read cost: 9.5129e-05 sec.
I1025 11:12:06.351161 31760 feature_common_inl.h:56] StreamingFeatureTpl<F>::Read cost: 0.00357008 sec.
I1025 11:12:06.351287 31760 cmvn.cc:57] CMVN::Read cost: 0.000106812 sec.
I1025 11:12:06.351336 31760 feature_cache.cc:100] FeatureCache::Compute cost: 2.40803e-05 sec. 34 feats.
I1025 11:12:06.351351 31760 audio_cache.cc:94] AudioCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.351358 31760 u2_recognizer.cc:72] feed waves cost: 0.00399208 sec. 5760 samples.
I1025 11:12:06.353883 31760 audio_cache.cc:52] AudioCache::Accept cost: 0.000118017 sec. 5760 samples.
I1025 11:12:06.353998 31760 audio_cache.cc:94] AudioCache::Read cost: 0.000102043 sec.
I1025 11:12:06.357677 31760 feature_common_inl.h:56] StreamingFeatureTpl<F>::Read cost: 0.00366902 sec.
I1025 11:12:06.357731 31760 cmvn.cc:57] CMVN::Read cost: 4.1008e-05 sec.
I1025 11:12:06.357774 31760 feature_cache.cc:100] FeatureCache::Compute cost: 3.31402e-05 sec. 36 feats.
I1025 11:12:06.357787 31760 audio_cache.cc:94] AudioCache::Read cost: 4.05312e-06 sec.
I1025 11:12:06.357796 31760 u2_recognizer.cc:72] feed waves cost: 0.00403404 sec. 5760 samples.
zh794390558 commented 2 years ago

从feat cache里读,大概耗时 0.000409126 sec

1025 11:12:06.357796 31760 u2_recognizer.cc:72] feed waves cost: 0.00403404 sec. 5760 samples.
I1025 11:12:06.357813 31760 feature_cache.cc:66] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 11:12:06.357822 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.357829 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.357837 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.357844 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.8147e-06 sec.
I1025 11:12:06.357852 31760 feature_cache.cc:66] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 11:12:06.357868 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.357877 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.357887 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.357897 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.357905 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.357914 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.357987 31760 feature_cache.cc:66] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 11:12:06.357995 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.358002 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358011 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358018 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358036 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.8147e-06 sec.
I1025 11:12:06.358049 31760 feature_cache.cc:66] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 11:12:06.358060 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358069 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358078 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358086 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.358095 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358111 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.358119 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358129 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.358137 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358146 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358156 31760 feature_cache.cc:66] FeatureCache::Read cost: 4.05312e-06 sec.
I1025 11:12:06.358165 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.358175 31760 feature_cache.cc:66] FeatureCache::Read cost: 2.86102e-06 sec.
I1025 11:12:06.358183 31760 feature_cache.cc:66] FeatureCache::Read cost: 3.09944e-06 sec.
I1025 11:12:06.358206 31760 assembler.cc:45] Assembler::Read cost: 0.000396013 sec.
I1025 11:12:06.358219 31760 decodable.cc:74] AdvanceChunk feat cost: 0.000409126 sec.
zh794390558 commented 2 years ago

feat + encoder forward cost

I1026 08:37:46.140666 41340 decodable.cc:74] AdvanceChunk feat cost: 0.00032711 sec.
I1026 08:37:46.369690 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.229352 sec.
I1026 08:37:46.391527 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000279903 sec.
I1026 08:37:46.649183 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.257937 sec.
I1026 08:37:46.671388 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000185966 sec.
I1026 08:37:46.874725 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.203524 sec.
I1026 08:37:46.899660 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000123978 sec.
I1026 08:37:47.103539 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.204004 sec.
I1026 08:37:47.126267 41340 decodable.cc:74] AdvanceChunk feat cost: 4.19617e-05 sec.
I1026 08:37:47.336185 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.209962 sec.
I1026 08:37:47.352663 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000295162 sec.
I1026 08:37:47.560456 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.208089 sec.
I1026 08:37:47.580680 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000233889 sec.
I1026 08:37:47.813848 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.233403 sec.
I1026 08:37:48.319069 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000349998 sec.
I1026 08:37:48.494313 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.175596 sec.
I1026 08:37:48.515704 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000247002 sec.
I1026 08:37:48.692641 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.177184 sec.
I1026 08:37:48.716533 41340 decodable.cc:74] AdvanceChunk feat cost: 0.00019598 sec.
I1026 08:37:48.899714 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.183378 sec.
I1026 08:37:48.924224 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000112057 sec.
I1026 08:37:49.111941 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.187831 sec.
I1026 08:37:49.136405 41340 decodable.cc:74] AdvanceChunk feat cost: 3.91006e-05 sec.
I1026 08:37:49.326768 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.190404 sec.
I1026 08:37:49.345409 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000287056 sec.
I1026 08:37:49.539398 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.194278 sec.
I1026 08:37:49.553588 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000179052 sec.
I1026 08:37:49.757208 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.2038 sec.
I1026 08:37:50.113597 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000329018 sec.
I1026 08:37:50.288746 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.175479 sec.
I1026 08:37:50.310312 41340 decodable.cc:74] AdvanceChunk feat cost: 0.000262022 sec.
I1026 08:37:50.486153 41340 decodable.cc:92] AdvanceChunk feat + forward cost: 0.176107 sec.
zh794390558 commented 2 years ago

encoder forward cost:

I1026 08:37:55.249452 41340 u2_nnet.cc:183] FeedForward cost: 0.192603 sec. 67 frames.
I1026 08:37:55.464820 41340 u2_nnet.cc:183] FeedForward cost: 0.19623 sec. 67 frames.
I1026 08:37:55.710062 41340 u2_nnet.cc:183] FeedForward cost: 0.228483 sec. 45 frames.
I1026 08:37:56.221678 41340 u2_nnet.cc:183] FeedForward cost: 0.176998 sec. 67 frames.
I1026 08:37:56.423399 41340 u2_nnet.cc:183] FeedForward cost: 0.177948 sec. 67 frames.
I1026 08:37:56.630831 41340 u2_nnet.cc:183] FeedForward cost: 0.18289 sec. 67 frames.
I1026 08:37:56.839424 41340 u2_nnet.cc:183] FeedForward cost: 0.186013 sec. 67 frames.
I1026 08:37:57.053583 41340 u2_nnet.cc:183] FeedForward cost: 0.190267 sec. 67 frames.
I1026 08:37:57.277899 41340 u2_nnet.cc:183] FeedForward cost: 0.212042 sec. 28 frames.
I1026 08:37:57.742313 41340 u2_nnet.cc:183] FeedForward cost: 0.174363 sec. 67 frames.
I1026 08:37:57.940871 41340 u2_nnet.cc:183] FeedForward cost: 0.176764 sec. 67 frames.
I1026 08:37:58.145676 41340 u2_nnet.cc:183] FeedForward cost: 0.18215 sec. 67 frames.
I1026 08:37:58.356184 41340 u2_nnet.cc:183] FeedForward cost: 0.185435 sec. 67 frames.
I1026 08:37:58.571422 41340 u2_nnet.cc:183] FeedForward cost: 0.190377 sec. 67 frames.
I1026 08:37:58.786494 41340 u2_nnet.cc:183] FeedForward cost: 0.196168 sec. 67 frames.
I1026 08:37:59.063647 41340 u2_nnet.cc:183] FeedForward cost: 0.253913 sec. 59 frames.
I1026 08:37:59.604249 41340 u2_nnet.cc:183] FeedForward cost: 0.174643 sec. 67 frames.
I1026 08:37:59.803678 41340 u2_nnet.cc:183] FeedForward cost: 0.177455 sec. 67 frames.
I1026 08:38:00.011544 41340 u2_nnet.cc:183] FeedForward cost: 0.183247 sec. 67 frames.
I1026 08:38:00.226353 41340 u2_nnet.cc:183] FeedForward cost: 0.189827 sec. 67 frames.
I1026 08:38:00.446251 41340 u2_nnet.cc:183] FeedForward cost: 0.195108 sec. 67 frames.
I1026 08:38:00.675060 41340 u2_nnet.cc:183] FeedForward cost: 0.21646 sec. 35 frames.
I1026 08:38:01.161279 41340 u2_nnet.cc:183] FeedForward cost: 0.176233 sec. 67 frames.
I1026 08:38:01.363968 41340 u2_nnet.cc:183] FeedForward cost: 0.18075 sec. 67 frames.
I1026 08:38:01.572247 41340 u2_nnet.cc:183] FeedForward cost: 0.183806 sec. 67 frames.
I1026 08:38:01.783692 41340 u2_nnet.cc:183] FeedForward cost: 0.18633 sec. 67 frames.
I1026 08:38:01.997499 41340 u2_nnet.cc:183] FeedForward cost: 0.191113 sec. 67 frames.
I1026 08:38:02.180944 41340 u2_nnet.cc:183] FeedForward cost: 0.170937 sec. 37 frames.
I1026 08:38:02.647246 41340 u2_nnet.cc:183] FeedForward cost: 0.176531 sec. 67 frames.
I1026 08:38:02.846612 41340 u2_nnet.cc:183] FeedForward cost: 0.177806 sec. 67 frames.
I1026 08:38:03.052842 41340 u2_nnet.cc:183] FeedForward cost: 0.182016 sec. 67 frames.
I1026 08:38:03.265743 41340 u2_nnet.cc:183] FeedForward cost: 0.188286 sec. 67 frames.
I1026 08:38:03.482489 41340 u2_nnet.cc:183] FeedForward cost: 0.19409 sec. 67 frames.
I1026 08:38:03.698926 41340 u2_nnet.cc:183] FeedForward cost: 0.197593 sec. 67 frames.
I1026 08:38:03.923884 41340 u2_nnet.cc:183] FeedForward cost: 0.20017 sec. 67 frames.
I1026 08:38:04.149483 41340 u2_nnet.cc:183] FeedForward cost: 0.202009 sec. 67 frames.
zh794390558 commented 2 years ago

ctc prefix beam search cost

I1026 08:37:48.705703 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00960135 sec.
I1026 08:37:48.712352 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:48.913555 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0102398 sec.
I1026 08:37:48.920085 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:49.125761 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0101471 sec.
I1026 08:37:49.132386 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:49.341006 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0103803 sec.
I1026 08:37:49.551412 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00879025 sec.
I1026 08:37:49.760579 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00292206 sec.
I1026 08:37:50.109230 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:50.299701 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00777054 sec.
I1026 08:37:50.306011 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:50.497807 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0083673 sec.
I1026 08:37:50.504220 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:50.704327 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0100732 sec.
I1026 08:37:50.710790 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:50.914898 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0102894 sec.
I1026 08:37:50.921531 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:51.132508 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0101938 sec.
I1026 08:37:51.345423 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00885415 sec.
I1026 08:37:51.540789 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00126576 sec.
I1026 08:37:51.859215 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:52.049634 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00780153 sec.
I1026 08:37:52.056092 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:52.249709 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00836468 sec.
I1026 08:37:52.256103 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:52.452659 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00828743 sec.
I1026 08:37:52.459195 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:52.661928 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0103257 sec.
I1026 08:37:52.668586 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:52.872433 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00866914 sec.
I1026 08:37:53.086763 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.01055 sec.
I1026 08:37:53.093257 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:53.316051 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.010922 sec.
I1026 08:37:53.322547 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:53.741093 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0115576 sec.
I1026 08:37:54.241752 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:54.432708 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00906205 sec.
I1026 08:37:54.439249 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:54.630859 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0082972 sec.
I1026 08:37:54.637090 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:54.836887 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0097537 sec.
I1026 08:37:54.843484 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:55.045758 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.010314 sec.
I1026 08:37:55.052765 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:55.264135 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.0105677 sec.
I1026 08:37:55.477198 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00876951 sec.
I1026 08:37:55.716753 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00572062 sec.
I1026 08:37:56.039737 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
I1026 08:37:56.234709 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0.00922608 sec.
I1026 08:37:56.241231 41340 ctc_prefix_beam_search_decoder.cc:94] AdvanceDecode search  cost: 0 sec.
zh794390558 commented 2 years ago

AttentionRescore

new

I1026 11:17:58.992323 45766 decodable.cc:174] Attention Rescoring cost:  0.383965 sec.
I1026 11:18:00.606349 45766 decodable.cc:174] Attention Rescoring cost:  0.305292 sec.
I1026 11:18:02.185619 45766 decodable.cc:174] Attention Rescoring cost:  0.276788 sec.
I1026 11:18:04.334728 45766 decodable.cc:174] Attention Rescoring cost:  0.421687 sec.
I1026 11:18:05.987941 45766 decodable.cc:174] Attention Rescoring cost:  0.286463 sec.
I1026 11:18:07.375057 45766 decodable.cc:174] Attention Rescoring cost:  0.245458 sec.
I1026 11:18:09.097123 45766 decodable.cc:174] Attention Rescoring cost:  0.308447 sec.
I1026 11:18:10.518599 45766 decodable.cc:174] Attention Rescoring cost:  0.264719 sec.
I1026 11:18:11.874912 45766 decodable.cc:174] Attention Rescoring cost:  0.243455 sec.
I1026 11:18:13.936547 45766 decodable.cc:174] Attention Rescoring cost:  0.354784 sec.
I1026 11:18:15.885727 45766 decodable.cc:174] Attention Rescoring cost:  0.355183 sec.
I1026 11:18:17.249020 45766 decodable.cc:174] Attention Rescoring cost:  0.235988 sec.
I1026 11:18:18.617604 45766 decodable.cc:174] Attention Rescoring cost:  0.263882 sec.
I1026 11:18:20.323796 45766 decodable.cc:174] Attention Rescoring cost:  0.319519 sec.
I1026 11:18:21.822944 45766 decodable.cc:174] Attention Rescoring cost:  0.284352 sec.
I1026 11:18:23.926913 45766 decodable.cc:174] Attention Rescoring cost:  0.402777 sec.
I1026 11:18:25.406139 45766 decodable.cc:174] Attention Rescoring cost:  0.256238 sec.
I1026 11:18:26.802487 45766 decodable.cc:174] Attention Rescoring cost:  0.240917 sec.
I1026 11:18:28.169536 45766 decodable.cc:174] Attention Rescoring cost:  0.247715 sec.
I1026 11:18:30.632380 45766 decodable.cc:174] Attention Rescoring cost:  0.386469 sec.

old

I1026 08:37:48.307390 41340 decodable.cc:174] Attention Rescoring takes 0.488862 sec.
I1026 08:37:50.101769 41340 decodable.cc:174] Attention Rescoring takes 0.341033 sec.
I1026 08:37:51.851532 41340 decodable.cc:174] Attention Rescoring takes 0.310585 sec.
I1026 08:37:54.234442 41340 decodable.cc:174] Attention Rescoring takes 0.493128 sec.
I1026 08:37:56.032487 41340 decodable.cc:174] Attention Rescoring takes 0.315565 sec.
I1026 08:37:57.555963 41340 decodable.cc:174] Attention Rescoring takes 0.273116 sec.
I1026 08:37:59.417840 41340 decodable.cc:174] Attention Rescoring takes 0.343092 sec.
I1026 08:38:00.973130 41340 decodable.cc:174] Attention Rescoring takes 0.292479 sec.
I1026 08:38:02.458737 41340 decodable.cc:174] Attention Rescoring takes 0.272448 sec.
I1026 08:38:04.705348 41340 decodable.cc:174] Attention Rescoring takes 0.382399 sec.
I1026 08:38:06.874070 41340 decodable.cc:174] Attention Rescoring takes 0.389147 sec.
I1026 08:38:08.386339 41340 decodable.cc:174] Attention Rescoring takes 0.265454 sec.
I1026 08:38:09.883886 41340 decodable.cc:174] Attention Rescoring takes 0.291481 sec.
I1026 08:38:11.643579 41340 decodable.cc:174] Attention Rescoring takes 0.334967 sec.
I1026 08:38:13.208990 41340 decodable.cc:174] Attention Rescoring takes 0.303692 sec.
I1026 08:38:15.371891 41340 decodable.cc:174] Attention Rescoring takes 0.421971 sec.
I1026 08:38:16.925714 41340 decodable.cc:174] Attention Rescoring takes 0.276879 sec.
I1026 08:38:18.402405 41340 decodable.cc:174] Attention Rescoring takes 0.259606 sec.
I1026 08:38:19.847769 41340 decodable.cc:174] Attention Rescoring takes 0.266272 sec.
I1026 08:38:22.442502 41340 decodable.cc:174] Attention Rescoring takes 0.417539 sec.