replay: support for external data

[namhyung]

There were some requests that it'd be nice to see some external data along with uftrace replay. It can be another process, user input or async event from the system. The simplest way I can think of is to have a text file describes the data with timestamp. The timestamp should be in sync with uftrace data (in nanosecond of the monotonic clock). The rest of the line will be treated as a message.

Here goes an example:

$ uftrace record  tests/t-abc

$ cat > uftrace.data/extern.dat
# this is external data for uftrace
31178.2489970	message from user
^D

$ uftrace replay -f +time
# DURATION     TID        TIMESTAMP       FUNCTION
   2.127 us [ 24141]    31178.248988259 | __monstartup();
   0.689 us [ 24141]    31178.248995043 | __cxa_atexit();
            [ 24141]    31178.248996884 | main() {
            [ 24141]    31178.248997000 | /* external-data: message from user */
            [ 24141]    31178.248997008 |   a() {
            [ 24141]    31178.248997166 |     b() {
            [ 24141]    31178.248997275 |       c() {
   0.972 us [ 24141]    31178.248997420 |         getpid();
   1.798 us [ 24141]    31178.248999073 |       } /* c */
   2.133 us [ 24141]    31178.248999299 |     } /* b */
   2.411 us [ 24141]    31178.248999419 |   } /* a */
   2.634 us [ 24141]    31178.248999518 | } /* main */

The code is available in review/extern-data-v1 branch.

[honggyukim]

It looks an interesting feature. I have some comments on this.

• What about using elapsed time? It seems that timestamp is too long to read. It can be optional.
• How does tid is decided for multi process/thread programs?
• If extern data has the same timestamp, I think it would be better to show it before normal record.
• It would be better to set the depth accordingly.
• It can be interesting to have a way to make an extern note when TUI replay mode is implemented. :)

Thanks for doing this work!

[honggyukim]

One of the useful usage is to leave a note of function prototypes so that users can understand the meaning of each argument value.

For this purpose, it can also be good to have a way to leave a note for some specific function.

$ cat > uftrace.data/extern.dat
# this is external data for uftrace
31178.2489970	message from user
getpid	pid_t getpid(void)
^D

$ uftrace replay -f +time
# DURATION     TID        TIMESTAMP       FUNCTION
   2.127 us [ 24141]    31178.248988259 | __monstartup();
   0.689 us [ 24141]    31178.248995043 | __cxa_atexit();
            [ 24141]    31178.248996884 | main() {
                        31178.248997000 |   /* external-data: message from user */
            [ 24141]    31178.248997008 |   a() {
            [ 24141]    31178.248997166 |     b() {
            [ 24141]    31178.248997275 |       c() {
                                        |         /* pid_t getpid(void) */
   0.972 us [ 24141]    31178.248997420 |         getpid();
   1.798 us [ 24141]    31178.248999073 |       } /* c */
   2.133 us [ 24141]    31178.248999299 |     } /* b */
   2.411 us [ 24141]    31178.248999419 |   } /* a */
   2.634 us [ 24141]    31178.248999518 | } /* main */

[ParkHanbum]

@namhyung I love this. Greate JOB!!!

[namhyung]

@honggyukim I expect timestamp would be recorded by other means independent to uftrace. The task was selected randomly (using last task) for external data as it has no connection to task. That's why I put the event at depth 0 unconditionally.

For function prototype I don't see the value of it. And it should be handled differently IMO.

[DanielTimLee]

Color support for the external data might be great.

~/t/v/w/t/m/u/uftrace.data  $ cat extern.dat
10303.321808251 \033[0;31m RED \033[0m color support?
========================================================================
            [  3659]    10303.321807048 |         getname() {
            [  3659]    10303.321807604 |           getname_flags() {
            [  3659]    10303.321808251 |             kmem_cache_alloc() {
            [  3659]    10303.321808251 | /* external-data: \033[0;31m RED \033[0m color support? */
            [  3659]    10303.321808771 |               _cond_resched() {

[namhyung]

You might replace the \033 into a real binary data (0x1b - ESC)...

[DanielTimLee]

[  3659]    10303.321808251 | /* external-data: 0x1B[0;31m RED 0x1B[0m color support? */

[  3659]    10303.321808251 | /* external-data: x1B[0;31m RED x1B[0m color support? */

[  3659]    10303.321808251 | /* external-data: \0x1B[0;31m RED \0x1B[0m color support? */

[  3659]    10303.321808251 | /* external-data: \x1B[0;31m RED \x1B[0m color support? */

[  3659]    10303.321808251 | /* external-data: 0x1b[0;31m RED 0x1b[0m color support? */

[  3659]    10303.321808251 | /* external-data: x1b[0;31m RED x1b[0m color support? */

[  3659]    10303.321808251 | /* external-data: \0x1b[0;31m RED \0x1b[0m color support? */

[  3659]    10303.321808251 | /* external-data: \x1b[0;31m RED \x1b[0m color support? */

Maybe [0;31m part should be encoded into binary data either?

[namhyung]

No I mean adding the raw data (not ascii representation). You need to check your editor supports that. Once it's done just cat will show the color as well.