1 The following are examples of rb_syscolors.d.
3 This is a simple script to trace the method flow of Ruby functions within a
4 program, and the system calls made. It renders the output in color ("colour")
5 using terminal escape sequences (which you can tweak by modifying the script).
7 Here it traces the example program, Code/Ruby/func_abc.rb.
9 WARNING: This output is full of terminal escape sequences, so if you are
10 trying to view this through an editor or web browser - it may look awful.
11 Try viewing this using "more" (although, depending on your terminal, it
12 still may look awful).
14 # rb_syscolors.d -c ./func_abc.rb
15 C PID DELTA(us) FILE:LINE TYPE -- NAME
16 \e[2;32m0 146499 2 ":- syscall -> munmap
\e[0m
17 \e[2;32m0 146499 35 ":- syscall <- munmap
\e[0m
18 \e[2;32m0 146499 56 ":- syscall -> mmap
\e[0m
19 \e[2;32m0 146499 18 ":- syscall <- mmap
\e[0m
20 \e[2;32m0 146499 41 ":- syscall -> setcontext
\e[0m
21 \e[2;32m0 146499 10 ":- syscall <- setcontext
\e[0m
22 \e[2;32m0 146499 10 ":- syscall -> getrlimit
\e[0m
23 \e[2;32m0 146499 11 ":- syscall <- getrlimit
\e[0m
24 \e[2;32m0 146499 9 ":- syscall -> getpid
\e[0m
25 \e[2;32m0 146499 8 ":- syscall <- getpid
\e[0m
26 \e[2;32m0 146499 66 ":- syscall -> setcontext
\e[0m
27 \e[2;32m0 146499 8 ":- syscall <- setcontext
\e[0m
28 \e[2;32m0 146499 1125 ":- syscall -> sysi86
\e[0m
29 \e[2;32m0 146499 12 ":- syscall <- sysi86
\e[0m
30 \e[2;32m0 146499 86 ":- syscall -> open64
\e[0m
31 \e[2;32m0 146499 89 ":- syscall <- open64
\e[0m
32 \e[2;32m0 146499 13 ":- syscall -> ioctl
\e[0m
33 \e[2;32m0 146499 35 ":- syscall <- ioctl
\e[0m
34 \e[2;32m0 146499 15 ":- syscall -> close
\e[0m
35 \e[2;32m0 146499 16 ":- syscall <- close
\e[0m
36 \e[2;32m0 146499 141 ":- syscall -> getrlimit64
\e[0m
37 \e[2;32m0 146499 10 ":- syscall <- getrlimit64
\e[0m
38 \e[2;32m0 146499 37 ":- syscall -> brk
\e[0m
39 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
40 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
41 \e[2;32m0 146499 17 ":- syscall <- brk
\e[0m
42 \e[2;32m0 146499 19 ":- syscall -> brk
\e[0m
43 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
44 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
45 \e[2;32m0 146499 11 ":- syscall <- brk
\e[0m
46 \e[2;32m0 146499 495 ":- syscall -> brk
\e[0m
47 \e[2;32m0 146499 11 ":- syscall <- brk
\e[0m
48 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
49 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
50 \e[2;32m0 146499 55 ":- syscall -> sysconfig
\e[0m
51 \e[2;32m0 146499 9 ":- syscall <- sysconfig
\e[0m
52 \e[2;32m0 146499 109 ":- syscall -> brk
\e[0m
53 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
54 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
55 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
56 \e[2;32m0 146499 189 ":- syscall -> brk
\e[0m
57 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
58 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
59 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
60 \e[2;32m0 146499 161 ":- syscall -> brk
\e[0m
61 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
62 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
63 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
64 \e[2;32m0 146499 144 ":- syscall -> brk
\e[0m
65 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
66 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
67 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
68 \e[2;32m0 146499 184 ":- syscall -> brk
\e[0m
69 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
70 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
71 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
72 \e[2;32m0 146499 129 ":- syscall -> brk
\e[0m
73 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
74 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
75 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
76 \e[2;32m0 146499 174 ":- syscall -> brk
\e[0m
77 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
78 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
79 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
80 \e[2;32m0 146499 145 ":- syscall -> brk
\e[0m
81 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
82 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
83 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
84 \e[2;32m0 146499 129 ":- syscall -> brk
\e[0m
85 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
86 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
87 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
88 \e[2;32m0 146499 134 ":- syscall -> brk
\e[0m
89 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
90 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
91 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
92 \e[2;32m0 146499 135 ":- syscall -> brk
\e[0m
93 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
94 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
95 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
96 \e[2;32m0 146499 136 ":- syscall -> brk
\e[0m
97 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
98 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
99 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
100 \e[2;32m0 146499 98 ":- syscall -> brk
\e[0m
101 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
102 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
103 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
104 \e[2;32m0 146499 132 ":- syscall -> brk
\e[0m
105 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
106 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
107 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
108 \e[2;32m0 146499 125 ":- syscall -> brk
\e[0m
109 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
110 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
111 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
112 \e[2;32m0 146499 189 ":- syscall -> brk
\e[0m
113 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
114 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
115 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
116 \e[2;32m0 146499 413 ":- syscall -> brk
\e[0m
117 \e[2;32m0 146499 11 ":- syscall <- brk
\e[0m
118 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
119 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
120 \e[2;32m0 146499 171 ":- syscall -> brk
\e[0m
121 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
122 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
123 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
124 \e[2;32m0 146499 137 ":- syscall -> brk
\e[0m
125 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
126 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
127 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
128 \e[2;32m0 146499 188 ":- syscall -> brk
\e[0m
129 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
130 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
131 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
132 \e[2;32m0 146499 135 ":- syscall -> sigaction
\e[0m
133 \e[2;32m0 146499 10 ":- syscall <- sigaction
\e[0m
134 \e[2;32m0 146499 10 ":- syscall -> sigaction
\e[0m
135 \e[2;32m0 146499 7 ":- syscall <- sigaction
\e[0m
136 \e[2;32m0 146499 8 ":- syscall -> sigaction
\e[0m
137 \e[2;32m0 146499 7 ":- syscall <- sigaction
\e[0m
138 \e[2;32m0 146499 8 ":- syscall -> sigaction
\e[0m
139 \e[2;32m0 146499 7 ":- syscall <- sigaction
\e[0m
140 \e[2;32m0 146499 8 ":- syscall -> sigaction
\e[0m
141 \e[2;32m0 146499 7 ":- syscall <- sigaction
\e[0m
142 \e[2;32m0 146499 8 ":- syscall -> sigaction
\e[0m
143 \e[2;32m0 146499 8 ":- syscall <- sigaction
\e[0m
144 \e[2;32m0 146499 8 ":- syscall -> sigaction
\e[0m
145 \e[2;32m0 146499 7 ":- syscall <- sigaction
\e[0m
146 \e[2;32m0 146499 9 ":- syscall -> sigaction
\e[0m
147 \e[2;32m0 146499 7 ":- syscall <- sigaction
\e[0m
148 \e[2;32m0 146499 8 ":- syscall -> sigaction
\e[0m
149 \e[2;32m0 146499 7 ":- syscall <- sigaction
\e[0m
150 \e[2;32m0 146499 12 ":- syscall -> sigpending
\e[0m
151 \e[2;32m0 146499 8 ":- syscall <- sigpending
\e[0m
152 \e[2;32m0 146499 15 ":- syscall -> schedctl
\e[0m
153 \e[2;32m0 146499 44 ":- syscall <- schedctl
\e[0m
154 \e[2;32m0 146499 17 ":- syscall -> lwp_sigmask
\e[0m
155 \e[2;32m0 146499 8 ":- syscall <- lwp_sigmask
\e[0m
156 \e[2;32m0 146499 9 ":- syscall -> sigaction
\e[0m
157 \e[2;32m0 146499 8 ":- syscall <- sigaction
\e[0m
158 \e[2;32m0 146499 11 ":- syscall -> lwp_sigmask
\e[0m
159 \e[2;32m0 146499 8 ":- syscall <- lwp_sigmask
\e[0m
160 \e[2;32m0 146499 9 ":- syscall -> lwp_sigmask
\e[0m
161 \e[2;32m0 146499 7 ":- syscall <- lwp_sigmask
\e[0m
162 \e[2;32m0 146499 8 ":- syscall -> sigaction
\e[0m
163 \e[2;32m0 146499 7 ":- syscall <- sigaction
\e[0m
164 \e[2;32m0 146499 8 ":- syscall -> lwp_sigmask
\e[0m
165 \e[2;32m0 146499 7 ":- syscall <- lwp_sigmask
\e[0m
166 \e[2;32m0 146499 65 ":- syscall -> brk
\e[0m
167 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
168 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
169 \e[2;32m0 146499 11 ":- syscall <- brk
\e[0m
170 \e[2;32m0 146499 149 ":- syscall -> getuid
\e[0m
171 \e[2;32m0 146499 9 ":- syscall <- getuid
\e[0m
172 \e[2;32m0 146499 12 ":- syscall -> getgid
\e[0m
173 \e[2;32m0 146499 8 ":- syscall <- getgid
\e[0m
174 \e[2;32m0 146499 29 ":- syscall -> brk
\e[0m
175 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
176 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
177 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
178 \e[2;32m0 146499 184 ":- syscall -> brk
\e[0m
179 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
180 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
181 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
182 \e[2;32m0 146499 171 ":- syscall -> brk
\e[0m
183 \e[2;32m0 146499 9 ":- syscall <- brk
\e[0m
184 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
185 \e[2;32m0 146499 10 ":- syscall <- brk
\e[0m
186 \e[2;32m0 146499 48 ":- syscall -> getuid
\e[0m
187 \e[2;32m0 146499 8 ":- syscall <- getuid
\e[0m
188 \e[2;32m0 146499 9 ":- syscall -> getuid
\e[0m
189 \e[2;32m0 146499 7 ":- syscall <- getuid
\e[0m
190 \e[2;32m0 146499 10 ":- syscall -> getgid
\e[0m
191 \e[2;32m0 146499 7 ":- syscall <- getgid
\e[0m
192 \e[2;32m0 146499 8 ":- syscall -> getgid
\e[0m
193 \e[2;32m0 146499 7 ":- syscall <- getgid
\e[0m
194 \e[2;32m0 146499 79 ":- syscall -> open64
\e[0m
195 \e[2;32m0 146499 31 ":- syscall <- open64
\e[0m
196 \e[2;32m0 146499 14 ":- syscall -> llseek
\e[0m
197 \e[2;32m0 146499 9 ":- syscall <- llseek
\e[0m
198 \e[2;32m0 146499 9 ":- syscall -> close
\e[0m
199 \e[2;32m0 146499 12 ":- syscall <- close
\e[0m
200 \e[2;32m0 146499 15 ":- syscall -> open64
\e[0m
201 \e[2;32m0 146499 13 ":- syscall <- open64
\e[0m
202 \e[2;32m0 146499 21 ":- syscall -> fstat64
\e[0m
203 \e[2;32m0 146499 11 ":- syscall <- fstat64
\e[0m
204 \e[2;32m0 146499 22 ":- syscall -> read
\e[0m
205 \e[2;32m0 146499 36 ":- syscall <- read
\e[0m
206 \e[2;32m0 146499 153 ":- syscall -> read
\e[0m
207 \e[2;32m0 146499 10 ":- syscall <- read
\e[0m
208 \e[2;32m0 146499 11 ":- syscall -> llseek
\e[0m
209 \e[2;32m0 146499 8 ":- syscall <- llseek
\e[0m
210 \e[2;32m0 146499 8 ":- syscall -> close
\e[0m
211 \e[2;32m0 146499 9 ":- syscall <- close
\e[0m
212 \e[1;35m0 146499 23 func_abc.rb:3 line --
\e[0m
213 \e[2;35m0 146499 64 func_abc.rb:3 method -> Module::method_added
\e[0m
214 \e[2;35m0 146499 24 func_abc.rb:3 method <- Module::method_added
\e[0m
215 \e[1;35m0 146499 20 func_abc.rb:8 line --
\e[0m
216 \e[2;35m0 146499 15 func_abc.rb:8 method -> Module::method_added
\e[0m
217 \e[2;35m0 146499 13 func_abc.rb:8 method <- Module::method_added
\e[0m
218 \e[1;35m0 146499 13 func_abc.rb:14 line --
\e[0m
219 \e[2;35m0 146499 14 func_abc.rb:14 method -> Module::method_added
\e[0m
220 \e[2;35m0 146499 13 func_abc.rb:14 method <- Module::method_added
\e[0m
221 \e[1;35m0 146499 12 func_abc.rb:20 line --
\e[0m
222 \e[2;35m0 146499 13 func_abc.rb:20 method -> Object::func_a
\e[0m
223 \e[1;35m0 146499 12 func_abc.rb:15 line --
\e[0m
224 \e[2;35m0 146499 10 func_abc.rb:15 method -> Object::print
\e[0m
225 \e[2;35m0 146499 22 func_abc.rb:15 method -> IO::write
\e[0m
226 \e[2;32m0 146499 38 ":- syscall -> ioctl
\e[0m
227 \e[2;32m0 146499 11 ":- syscall <- ioctl
\e[0m
228 \e[2;32m0 146499 20 ":- syscall -> fstat64
\e[0m
229 \e[2;32m0 146499 9 ":- syscall <- fstat64
\e[0m
230 \e[2;32m0 146499 9 ":- syscall -> brk
\e[0m
231 \e[2;32m0 146499 8 ":- syscall <- brk
\e[0m
232 \e[2;32m0 146499 8 ":- syscall -> brk
\e[0m
233 \e[2;32m0 146499 11 ":- syscall <- brk
\e[0m
234 \e[2;32m0 146499 25 ":- syscall -> fstat64
\e[0m
235 \e[2;32m0 146499 8 ":- syscall <- fstat64
\e[0m
236 \e[2;35m0 146499 10 func_abc.rb:15 method <- IO::write
\e[0m
237 \e[2;35m0 146499 13 func_abc.rb:15 method <- Object::print
\e[0m
238 \e[1;35m0 146499 12 func_abc.rb:16 line --
\e[0m
239 \e[2;35m0 146499 10 func_abc.rb:16 method -> Object::sleep
\e[0m
240 \e[2;32m0 146499 20 ":- syscall -> gtime
\e[0m
241 \e[2;32m0 146499 9 ":- syscall <- gtime
\e[0m
242 \e[2;32m0 146499 24 ":- syscall -> pollsys
\e[0m
243 \e[2;32m0 146499 1006964 ":- syscall <- pollsys
\e[0m
244 \e[2;32m0 146499 26 ":- syscall -> gtime
\e[0m
245 \e[2;32m0 146499 14 ":- syscall <- gtime
\e[0m
246 \e[2;35m0 146499 18 func_abc.rb:16 method <- Object::sleep
\e[0m
247 \e[1;35m0 146499 27 func_abc.rb:17 line --
\e[0m
248 \e[2;35m0 146499 21 func_abc.rb:17 method -> Object::func_b
\e[0m
249 \e[1;35m0 146499 19 func_abc.rb:9 line --
\e[0m
250 \e[2;35m0 146499 12 func_abc.rb:9 method -> Object::print
\e[0m
251 \e[2;35m0 146499 14 func_abc.rb:9 method -> IO::write
\e[0m
252 \e[2;35m0 146499 15 func_abc.rb:9 method <- IO::write
\e[0m
253 \e[2;35m0 146499 12 func_abc.rb:9 method <- Object::print
\e[0m
254 \e[1;35m0 146499 12 func_abc.rb:10 line --
\e[0m
255 \e[2;35m0 146499 9 func_abc.rb:10 method -> Object::sleep
\e[0m
256 \e[2;32m0 146499 12 ":- syscall -> gtime
\e[0m
257 \e[2;32m0 146499 8 ":- syscall <- gtime
\e[0m
258 \e[2;32m0 146499 11 ":- syscall -> pollsys
\e[0m
259 \e[2;32m0 146499 1009739 ":- syscall <- pollsys
\e[0m
260 \e[2;32m0 146499 26 ":- syscall -> gtime
\e[0m
261 \e[2;32m0 146499 14 ":- syscall <- gtime
\e[0m
262 \e[2;35m0 146499 18 func_abc.rb:10 method <- Object::sleep
\e[0m
263 \e[1;35m0 146499 27 func_abc.rb:11 line --
\e[0m
264 \e[2;35m0 146499 21 func_abc.rb:11 method -> Object::func_c
\e[0m
265 \e[1;35m0 146499 20 func_abc.rb:4 line --
\e[0m
266 \e[2;35m0 146499 12 func_abc.rb:4 method -> Object::print
\e[0m
267 \e[2;35m0 146499 14 func_abc.rb:4 method -> IO::write
\e[0m
268 \e[2;35m0 146499 15 func_abc.rb:4 method <- IO::write
\e[0m
269 \e[2;35m0 146499 12 func_abc.rb:4 method <- Object::print
\e[0m
270 \e[1;35m0 146499 12 func_abc.rb:5 line --
\e[0m
271 \e[2;35m0 146499 9 func_abc.rb:5 method -> Object::sleep
\e[0m
272 \e[2;32m0 146499 12 ":- syscall -> gtime
\e[0m
273 \e[2;32m0 146499 8 ":- syscall <- gtime
\e[0m
274 \e[2;32m0 146499 11 ":- syscall -> pollsys
\e[0m
278 \e[2;32m0 146499 1009762 ":- syscall <- pollsys
\e[0m
279 \e[2;32m0 146499 25 ":- syscall -> gtime
\e[0m
280 \e[2;32m0 146499 14 ":- syscall <- gtime
\e[0m
281 \e[2;35m0 146499 19 func_abc.rb:5 method <- Object::sleep
\e[0m
282 \e[2;35m0 146499 26 func_abc.rb:5 method <- Object::func_c
\e[0m
283 \e[2;35m0 146499 13 func_abc.rb:11 method <- Object::func_b
\e[0m
284 \e[2;35m0 146499 13 func_abc.rb:17 method <- Object::func_a
\e[0m
285 \e[2;32m0 146499 33 ":- syscall -> sigaction
\e[0m
286 \e[2;32m0 146499 10 ":- syscall <- sigaction
\e[0m
287 \e[2;32m0 146499 100 ":- syscall -> open64
\e[0m
288 \e[2;32m0 146499 107 ":- syscall <- open64
\e[0m
289 \e[2;32m0 146499 10 ":- syscall -> ioctl
\e[0m
290 \e[2;32m0 146499 10 ":- syscall <- ioctl
\e[0m
291 \e[2;32m0 146499 11 ":- syscall -> close
\e[0m
292 \e[2;32m0 146499 17 ":- syscall <- close
\e[0m
293 \e[2;32m0 146499 28 ":- syscall -> write
\e[0m
294 \e[2;32m0 146499 20 ":- syscall <- write
\e[0m
295 \e[2;32m0 146499 11 ":- syscall -> rexit
\e[0m
297 Here you can see the output showing the path the program follows in its
301 \e[2;35m0 146499 10 func_abc.rb:16 method -> Object::sleep
\e[0m
302 \e[2;32m0 146499 20 ":- syscall -> gtime
\e[0m
303 \e[2;32m0 146499 9 ":- syscall <- gtime
\e[0m
304 \e[2;32m0 146499 24 ":- syscall -> pollsys
\e[0m
305 \e[2;32m0 146499 1006964 ":- syscall <- pollsys
\e[0m
306 \e[2;32m0 146499 26 ":- syscall -> gtime
\e[0m
307 \e[2;32m0 146499 14 ":- syscall <- gtime
\e[0m
308 \e[2;35m0 146499 18 func_abc.rb:16 method <- Object::sleep
\e[0m
309 \e[1;35m0 146499 27 func_abc.rb:17 line --
\e[0m
310 \e[2;35m0 146499 21 func_abc.rb:17 method -> Object::func_b
\e[0m
311 \e[1;35m0 146499 19 func_abc.rb:9 line --
\e[0m
312 \e[2;35m0 146499 12 func_abc.rb:9 method -> Object::print
\e[0m
313 \e[2;35m0 146499 14 func_abc.rb:9 method -> IO::write
\e[0m
314 \e[2;35m0 146499 15 func_abc.rb:9 method <- IO::write
\e[0m
315 \e[2;35m0 146499 12 func_abc.rb:9 method <- Object::print
\e[0m
316 \e[1;35m0 146499 12 func_abc.rb:10 line --
\e[0m
318 shows that on cpu 0 the program is running a sleep command at line 16 of the
319 func_abc.rb program (the pollsys and gtime syscalls are used in the Ruby
320 engine to implement sleep). Then func_b runs, and prints a line
321 (using Object::print which uses IO::write). Notice that the 'write' syscall
322 does not happen until later. It is probably being buffered by Ruby - you can
323 confirm this through further DTracing. Notice also tht you can see the output
330 in the file happening before the write syscall is run. DTrace does not do its
331 output in 'real time'. There is a slight delay due to buffering.