@@ -4,7 +4,7 @@ use std::io::{BufWriter, Write};
44use std:: mem;
55use std:: process;
66use std:: thread:: ThreadId ;
7- use std:: time:: Instant ;
7+ use std:: time:: { Duration , Instant , SystemTime } ;
88
99use crate :: session:: config:: Options ;
1010
@@ -21,20 +21,20 @@ pub enum ProfileCategory {
2121
2222#[ derive( Clone , Copy , Debug , Eq , PartialEq ) ]
2323pub enum ProfilerEvent {
24- QueryStart { query_name : & ' static str , category : ProfileCategory , time : Instant } ,
25- QueryEnd { query_name : & ' static str , category : ProfileCategory , time : Instant } ,
26- GenericActivityStart { category : ProfileCategory , time : Instant } ,
27- GenericActivityEnd { category : ProfileCategory , time : Instant } ,
28- IncrementalLoadResultStart { query_name : & ' static str , time : Instant } ,
29- IncrementalLoadResultEnd { query_name : & ' static str , time : Instant } ,
30- QueryCacheHit { query_name : & ' static str , category : ProfileCategory , time : Instant } ,
31- QueryCount { query_name : & ' static str , category : ProfileCategory , count : usize , time : Instant } ,
32- QueryBlockedStart { query_name : & ' static str , category : ProfileCategory , time : Instant } ,
33- QueryBlockedEnd { query_name : & ' static str , category : ProfileCategory , time : Instant } ,
24+ QueryStart { query_name : & ' static str , category : ProfileCategory , time : u64 } ,
25+ QueryEnd { query_name : & ' static str , category : ProfileCategory , time : u64 } ,
26+ GenericActivityStart { category : ProfileCategory , time : u64 } ,
27+ GenericActivityEnd { category : ProfileCategory , time : u64 } ,
28+ IncrementalLoadResultStart { query_name : & ' static str , time : u64 } ,
29+ IncrementalLoadResultEnd { query_name : & ' static str , time : u64 } ,
30+ QueryCacheHit { query_name : & ' static str , category : ProfileCategory , time : u64 } ,
31+ QueryCount { query_name : & ' static str , category : ProfileCategory , count : usize , time : u64 } ,
32+ QueryBlockedStart { query_name : & ' static str , category : ProfileCategory , time : u64 } ,
33+ QueryBlockedEnd { query_name : & ' static str , category : ProfileCategory , time : u64 } ,
3434}
3535
3636impl ProfilerEvent {
37- fn timestamp ( & self ) -> Instant {
37+ fn timestamp ( & self ) -> u64 {
3838 use self :: ProfilerEvent :: * ;
3939
4040 match self {
@@ -58,32 +58,34 @@ fn thread_id_to_u64(tid: ThreadId) -> u64 {
5858
5959pub struct SelfProfiler {
6060 events : HashMap < ThreadId , Vec < ProfilerEvent > > ,
61+ start_time : SystemTime ,
62+ start_instant : Instant ,
6163}
6264
6365impl SelfProfiler {
6466 pub fn new ( ) -> SelfProfiler {
65- let mut profiler = SelfProfiler {
67+ let profiler = SelfProfiler {
6668 events : HashMap :: new ( ) ,
69+ start_time : SystemTime :: now ( ) ,
70+ start_instant : Instant :: now ( ) ,
6771 } ;
6872
69- profiler. start_activity ( ProfileCategory :: Other ) ;
70-
7173 profiler
7274 }
7375
7476 #[ inline]
7577 pub fn start_activity ( & mut self , category : ProfileCategory ) {
7678 self . record ( ProfilerEvent :: GenericActivityStart {
7779 category,
78- time : Instant :: now ( ) ,
80+ time : self . get_time_from_start ( ) ,
7981 } )
8082 }
8183
8284 #[ inline]
8385 pub fn end_activity ( & mut self , category : ProfileCategory ) {
8486 self . record ( ProfilerEvent :: GenericActivityEnd {
8587 category,
86- time : Instant :: now ( ) ,
88+ time : self . get_time_from_start ( ) ,
8789 } )
8890 }
8991
@@ -98,7 +100,7 @@ impl SelfProfiler {
98100 query_name,
99101 category,
100102 count,
101- time : Instant :: now ( ) ,
103+ time : self . get_time_from_start ( ) ,
102104 } )
103105 }
104106
@@ -107,7 +109,7 @@ impl SelfProfiler {
107109 self . record ( ProfilerEvent :: QueryCacheHit {
108110 query_name,
109111 category,
110- time : Instant :: now ( ) ,
112+ time : self . get_time_from_start ( ) ,
111113 } )
112114 }
113115
@@ -116,7 +118,7 @@ impl SelfProfiler {
116118 self . record ( ProfilerEvent :: QueryStart {
117119 query_name,
118120 category,
119- time : Instant :: now ( ) ,
121+ time : self . get_time_from_start ( ) ,
120122 } ) ;
121123 }
122124
@@ -125,23 +127,23 @@ impl SelfProfiler {
125127 self . record ( ProfilerEvent :: QueryEnd {
126128 query_name,
127129 category,
128- time : Instant :: now ( ) ,
130+ time : self . get_time_from_start ( ) ,
129131 } )
130132 }
131133
132134 #[ inline]
133135 pub fn incremental_load_result_start ( & mut self , query_name : & ' static str ) {
134136 self . record ( ProfilerEvent :: IncrementalLoadResultStart {
135137 query_name,
136- time : Instant :: now ( ) ,
138+ time : self . get_time_from_start ( ) ,
137139 } )
138140 }
139141
140142 #[ inline]
141143 pub fn incremental_load_result_end ( & mut self , query_name : & ' static str ) {
142144 self . record ( ProfilerEvent :: IncrementalLoadResultEnd {
143145 query_name,
144- time : Instant :: now ( ) ,
146+ time : self . get_time_from_start ( ) ,
145147 } )
146148 }
147149
@@ -150,7 +152,7 @@ impl SelfProfiler {
150152 self . record ( ProfilerEvent :: QueryBlockedStart {
151153 query_name,
152154 category,
153- time : Instant :: now ( ) ,
155+ time : self . get_time_from_start ( ) ,
154156 } )
155157 }
156158
@@ -159,7 +161,7 @@ impl SelfProfiler {
159161 self . record ( ProfilerEvent :: QueryBlockedEnd {
160162 query_name,
161163 category,
162- time : Instant :: now ( ) ,
164+ time : self . get_time_from_start ( ) ,
163165 } )
164166 }
165167
@@ -171,19 +173,15 @@ impl SelfProfiler {
171173 events. push ( event) ;
172174 }
173175
176+ #[ inline]
177+ fn get_time_from_start ( & self ) -> u64 {
178+ let duration = Instant :: now ( ) - self . start_instant ;
179+ duration. as_nanos ( ) as u64
180+ }
181+
174182 pub fn dump_raw_events ( & self , opts : & Options ) {
175183 use self :: ProfilerEvent :: * ;
176184
177- //find the earliest Instant to use as t=0
178- //when serializing the events, we'll calculate a Duration
179- //using (instant - min_instant)
180- let min_instant =
181- self . events
182- . iter ( )
183- . map ( |( _, values) | values[ 0 ] . timestamp ( ) )
184- . min ( )
185- . unwrap ( ) ;
186-
187185 let pid = process:: id ( ) ;
188186
189187 let filename =
@@ -229,8 +227,10 @@ impl SelfProfiler {
229227 }
230228
231229 let ( secs, nanos) = {
232- let duration = event. timestamp ( ) - min_instant;
233- ( duration. as_secs ( ) , duration. subsec_nanos ( ) )
230+ let time = self . start_time + Duration :: from_nanos ( event. timestamp ( ) ) ;
231+ let time_since_unix =
232+ time. duration_since ( SystemTime :: UNIX_EPOCH ) . unwrap_or_default ( ) ;
233+ ( time_since_unix. as_secs ( ) , time_since_unix. subsec_nanos ( ) )
234234 } ;
235235
236236 match event {
0 commit comments