@@ -4,7 +4,7 @@ use std::io::{BufWriter, Write};
4
4
use std:: mem;
5
5
use std:: process;
6
6
use std:: thread:: ThreadId ;
7
- use std:: time:: Instant ;
7
+ use std:: time:: { Duration , Instant , SystemTime } ;
8
8
9
9
use crate :: session:: config:: Options ;
10
10
@@ -21,20 +21,20 @@ pub enum ProfileCategory {
21
21
22
22
#[ derive( Clone , Copy , Debug , Eq , PartialEq ) ]
23
23
pub 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 } ,
34
34
}
35
35
36
36
impl ProfilerEvent {
37
- fn timestamp ( & self ) -> Instant {
37
+ fn timestamp ( & self ) -> u64 {
38
38
use self :: ProfilerEvent :: * ;
39
39
40
40
match self {
@@ -58,32 +58,34 @@ fn thread_id_to_u64(tid: ThreadId) -> u64 {
58
58
59
59
pub struct SelfProfiler {
60
60
events : HashMap < ThreadId , Vec < ProfilerEvent > > ,
61
+ start_time : SystemTime ,
62
+ start_instant : Instant ,
61
63
}
62
64
63
65
impl SelfProfiler {
64
66
pub fn new ( ) -> SelfProfiler {
65
- let mut profiler = SelfProfiler {
67
+ let profiler = SelfProfiler {
66
68
events : HashMap :: new ( ) ,
69
+ start_time : SystemTime :: now ( ) ,
70
+ start_instant : Instant :: now ( ) ,
67
71
} ;
68
72
69
- profiler. start_activity ( ProfileCategory :: Other ) ;
70
-
71
73
profiler
72
74
}
73
75
74
76
#[ inline]
75
77
pub fn start_activity ( & mut self , category : ProfileCategory ) {
76
78
self . record ( ProfilerEvent :: GenericActivityStart {
77
79
category,
78
- time : Instant :: now ( ) ,
80
+ time : self . get_time_from_start ( ) ,
79
81
} )
80
82
}
81
83
82
84
#[ inline]
83
85
pub fn end_activity ( & mut self , category : ProfileCategory ) {
84
86
self . record ( ProfilerEvent :: GenericActivityEnd {
85
87
category,
86
- time : Instant :: now ( ) ,
88
+ time : self . get_time_from_start ( ) ,
87
89
} )
88
90
}
89
91
@@ -98,7 +100,7 @@ impl SelfProfiler {
98
100
query_name,
99
101
category,
100
102
count,
101
- time : Instant :: now ( ) ,
103
+ time : self . get_time_from_start ( ) ,
102
104
} )
103
105
}
104
106
@@ -107,7 +109,7 @@ impl SelfProfiler {
107
109
self . record ( ProfilerEvent :: QueryCacheHit {
108
110
query_name,
109
111
category,
110
- time : Instant :: now ( ) ,
112
+ time : self . get_time_from_start ( ) ,
111
113
} )
112
114
}
113
115
@@ -116,7 +118,7 @@ impl SelfProfiler {
116
118
self . record ( ProfilerEvent :: QueryStart {
117
119
query_name,
118
120
category,
119
- time : Instant :: now ( ) ,
121
+ time : self . get_time_from_start ( ) ,
120
122
} ) ;
121
123
}
122
124
@@ -125,23 +127,23 @@ impl SelfProfiler {
125
127
self . record ( ProfilerEvent :: QueryEnd {
126
128
query_name,
127
129
category,
128
- time : Instant :: now ( ) ,
130
+ time : self . get_time_from_start ( ) ,
129
131
} )
130
132
}
131
133
132
134
#[ inline]
133
135
pub fn incremental_load_result_start ( & mut self , query_name : & ' static str ) {
134
136
self . record ( ProfilerEvent :: IncrementalLoadResultStart {
135
137
query_name,
136
- time : Instant :: now ( ) ,
138
+ time : self . get_time_from_start ( ) ,
137
139
} )
138
140
}
139
141
140
142
#[ inline]
141
143
pub fn incremental_load_result_end ( & mut self , query_name : & ' static str ) {
142
144
self . record ( ProfilerEvent :: IncrementalLoadResultEnd {
143
145
query_name,
144
- time : Instant :: now ( ) ,
146
+ time : self . get_time_from_start ( ) ,
145
147
} )
146
148
}
147
149
@@ -150,7 +152,7 @@ impl SelfProfiler {
150
152
self . record ( ProfilerEvent :: QueryBlockedStart {
151
153
query_name,
152
154
category,
153
- time : Instant :: now ( ) ,
155
+ time : self . get_time_from_start ( ) ,
154
156
} )
155
157
}
156
158
@@ -159,7 +161,7 @@ impl SelfProfiler {
159
161
self . record ( ProfilerEvent :: QueryBlockedEnd {
160
162
query_name,
161
163
category,
162
- time : Instant :: now ( ) ,
164
+ time : self . get_time_from_start ( ) ,
163
165
} )
164
166
}
165
167
@@ -171,19 +173,15 @@ impl SelfProfiler {
171
173
events. push ( event) ;
172
174
}
173
175
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
+
174
182
pub fn dump_raw_events ( & self , opts : & Options ) {
175
183
use self :: ProfilerEvent :: * ;
176
184
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
-
187
185
let pid = process:: id ( ) ;
188
186
189
187
let filename =
@@ -229,8 +227,10 @@ impl SelfProfiler {
229
227
}
230
228
231
229
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 ( ) )
234
234
} ;
235
235
236
236
match event {
0 commit comments