Blame view

src/online2/online-timing.cc 4.58 KB
8dcb6dfcb   Yannick Estève   first commit
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
  // online2/online-timing.cc
  
  // Copyright    2014  Johns Hopkins University (author: Daniel Povey)
  
  // See ../../COPYING for clarification regarding multiple authors
  //
  // Licensed under the Apache License, Version 2.0 (the "License");
  // you may not use this file except in compliance with the License.
  // You may obtain a copy of the License at
  //
  //  http://www.apache.org/licenses/LICENSE-2.0
  //
  // THIS CODE IS PROVIDED *AS IS* BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
  // KIND, EITHER EXPRESS OR IMPLIED, INCLUDING WITHOUT LIMITATION ANY IMPLIED
  // WARRANTIES OR CONDITIONS OF TITLE, FITNESS FOR A PARTICULAR PURPOSE,
  // MERCHANTABLITY OR NON-INFRINGEMENT.
  // See the Apache 2 License for the specific language governing permissions and
  // limitations under the License.
  
  #include "online2/online-timing.h"
  
  namespace kaldi {
  
  OnlineTimingStats::OnlineTimingStats():
      num_utts_(0), total_audio_(0.0), total_time_taken_(0.0),
      total_time_waited_(0.0), max_delay_(0.0) {
  }
  
  void OnlineTimingStats::Print(bool online){
    if (online) {
      double real_time_factor = total_time_taken_ / total_audio_,
          average_wait = (total_time_taken_ - total_audio_) / num_utts_,
          idle_proportion = total_time_waited_ / total_audio_,
          idle_percent = 100.0 * idle_proportion;
  
      KALDI_LOG << "Timing stats: real-time factor was " << real_time_factor
                << " (note: this cannot be less than one.)";
      KALDI_LOG << "Average delay was " << average_wait << " seconds.";
      if (idle_percent != 0.0) {
        // If the user was calling SleepUntil instead of WaitUntil, this will
        // always be zero; so don't print it in that case.
        KALDI_LOG << "Percentage of time spent idling was " << idle_percent;
      }
      KALDI_LOG << "Longest delay was " << max_delay_ << " seconds for utterance "
                << '\'' << max_delay_utt_ << '\'';
    } else {
      // we have processed each utterance in one chunk.
      // the decoding code will have "pretended to wait" (using WaitUntil())
      // till the end of the utterance before starting to decode it.
      // We want to subtract this waiting time, which is not really
      // of interest in an offline scenario, before printing the
      // real-time factor.
      double real_time_factor = (total_time_taken_ - total_time_waited_) /
          total_audio_;
      KALDI_LOG << "Timing stats: real-time factor for offline decoding was "
                << real_time_factor << " = "
                << (total_time_taken_ - total_time_waited_) << " seconds "
                << " / " << total_audio_ << " seconds.";
    }
  }
  
  OnlineTimer::OnlineTimer(const std::string &utterance_id):
      utterance_id_(utterance_id), waited_(0.0), utterance_length_(0.0) { }
  
  void OnlineTimer::WaitUntil(double cur_utterance_length) {
    double elapsed = timer_.Elapsed();
    // it's been cur_utterance_length seconds since we would have
    // started processing this utterance, in a real-time decoding
    // scenario.  We've been actually processing it for "elapsed"
    // seconds, plus we would have been waiting on some kind of
    // semaphore for waited_ seconds.  If we have to wait further
    // at this point, increase "waited_".
    // (I have to think of a better way of explaining this).
    double to_wait = cur_utterance_length - (elapsed + waited_);
    if (to_wait > 0.0)
      waited_ += to_wait;
  
    utterance_length_ = cur_utterance_length;
  }
  
  void OnlineTimer::SleepUntil(double cur_utterance_length) {
    KALDI_ASSERT(waited_ == 0 && "Do not mix SleepUntil with WaitUntil.");
    double elapsed = timer_.Elapsed();
  
    double to_wait = cur_utterance_length - elapsed;
    if (to_wait > 0.0) {
      Sleep(to_wait);
    }
    utterance_length_ = cur_utterance_length;
  }
  
  double OnlineTimer::Elapsed() {
    return timer_.Elapsed() + waited_;
  }
  
  void OnlineTimer::OutputStats(OnlineTimingStats *stats) {
    double processing_time = timer_.Elapsed() + waited_,
        wait_time = processing_time - utterance_length_;
    if (wait_time < 0.0) {
      // My first though was to make this a KALDI_ERR, but perhaps
      // clocks can go backwards under some weird circumstance, so
      // let's just make it a warning.
      KALDI_WARN << "Negative wait time " << wait_time
                 << " does not make sense.";
    }
    KALDI_VLOG(2) << "Latency " << wait_time << " seconds out of "
                  << utterance_length_ << ", for utterance "
                  << utterance_id_;
    
    stats->num_utts_++;
    stats->total_audio_ += utterance_length_;
    stats->total_time_taken_ += processing_time;
    stats->total_time_waited_ += waited_;
    if (wait_time > stats->max_delay_) {
      stats->max_delay_ = wait_time;
      stats->max_delay_utt_ = utterance_id_;
    }
  }
  
  
  }  // namespace kaldi