iipeace
Export tracing records in rows instead of multi-line structures
Some tracing data are offered as data structures which are distributed over multiple lines.
Example: Call and return information according to function executions
I suggest to provide corresponding values in a single row per data set on demand.
I became especially interested in efficient and safe analyses for function executions. I guess that other trace reports would be similarly affected. (Will the software documentation be improved accordingly?)
:eyes: I am looking for ways to combine available information (from some lines) into rows for further data processing approaches.
I suggest to take another look at analysis examples which you published already.
I guess that you wanna get a line including both function entry and return info. Is it right?
What do you think about this? It will only print return context.
# ./guider.py btrace yes -c "|filter:RETVAL:BT:0"
Such a functionality can occasionally be also useful. I hope that the software documentation will be improved.
But it is obvious that the mentioned filter example does not combine discussed data items, isn't it?
Yes, it doesn't combine function entry info. But the combined output will not displayed until the target function call is finished(return). is it okay?
What do you think about this output?
0.035559 write(1>/dev/null,0x55d092dbb440,0x2000)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000021 -> 0x4c40/0x55d092947000 [/usr/bin/yes]
0.035842 write(1>/dev/null,0x55d092dbb440,0x2000)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000021 -> 0x4c40/0x55d092947000 [/usr/bin/yes]
0.037240 write(1>/dev/null,0x55d092dbb440,0x2000)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000023 -> 0x4c40/0x55d092947000 [/usr/bin/yes]
0.046022 write(1>/dev/null,0x55d092dbb440,0x2000)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000021 -> 0x4c40/0x55d092947000 [/usr/bin/yes]
0.052150 write(1>/dev/null,0x55d092dbb440,0x2000)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000023 -> 0x4c40/0x55d092947000 [/usr/bin/yes]
0.082249 write(1>/dev/null,0x55d092dbb440,0x2000)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000022 -> 0x4c40/0x55d092947000 [/usr/bin/yes]
0.088081 write(1>/dev/null,0x55d092dbb440,0x2000)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000023 -> 0x4c40/0x55d092947000 [/usr/bin/yes]
But the combined output will not displayed until the target function call is finished(return). is it okay?
Yes ‒ for a configured software analysis variant (as proposed).
What do you think about this output?
The display looks promising. I would like to know more about the data items which are provided in such rows.
You can check a new feature with a below command.
$ ./guider.py btrace yes -c "write|getret" -q completecall
0.037839 write(0x1,0x558c8d83e440,0x2000,0x7f7728567640,0x558c8d83e440,0x7c)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000010 -> 0x4
0.037859 write(0x1,0x558c8d83e440,0x2000,0x7f7728567640,0x558c8d83e440,0x7c)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000010 -> 0x4
0.037879 write(0x1,0x558c8d83e440,0x2000,0x7f7728567640,0x558c8d83e440,0x7c)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000010 -> 0x4
0.037900 write(0x1,0x558c8d83e440,0x2000,0x7f7728567640,0x558c8d83e440,0x7c)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000010 -> 0x4
0.037920 write(0x1,0x558c8d83e440,0x2000,0x7f7728567640,0x558c8d83e440,0x7c)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000010 -> 0x4
0.037940 write(0x1,0x558c8d83e440,0x2000,0x7f7728567640,0x558c8d83e440,0x7c)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000010 -> 0x4
0.037960 write(0x1,0x558c8d83e440,0x2000,0x7f7728567640,0x558c8d83e440,0x7c)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000010 -> 0x4
0.037980 write(0x1,0x558c8d83e440,0x2000,0x7f7728567640,0x558c8d83e440,0x7c)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x2000(8192)/0.000010 -> 0x4
'''
Thanks for another positive feedback. :eyes: I am still looking for corresponding extensions according to the software documentation.
I tried one of my small test programs out once more.
[Markus_Elfring@fedora guider]$ ./guider.py btrace '/home/altes_Heim2/elfring/Projekte/Bau/QStorageInfo-setPath/QStorageInfo-setPath' -c 'statvfs64|getret' -q completecall
… ver_3.9.8_211002 on python_3.9
…
"2 20:00:02.327" Determining file system: "/home/Markus_Elfring/gui_rpc_auth.cfg"
"2 20:00:02.368" | "Data determination by setPath()" | 5730828 |ns
"2 20:00:02.371" type name: "ext4"
1.878231 +++ exited QStorageInfo-se(72007) with 0 +++
Now I am missing the analysis data output according to your software update.
is it okay without -q option?
No, not yet.
could you share your program binary?
The access to my executable file might not be directly needed for further test runs. I imagine that it will be more helpful to check if the tool “guider” will be able to provide analysis data also for calls of the function “statvfs64”. Other test programs can eventually help to clarify unexpected software behaviour better than my local file variants.
Otherwise: :crystal_ball: Would you like to construct a Qt console application where you would use a function implementation like the following?
void Task::call_API(QStorageInfo& info, QString const & input)
{
l_t x(QStringLiteral("Data determination by setPath()"));
info.setPath(input);
}
How will analysis data evolve together with Python programming interfaces like “os.statvfs(path)” (as another application example)? :thinking:
Would you like to add any unit test cases accordingly?
I tested on my PC using a below command.
root@osdc:/home/peacelee/guider/guider# ./guider.py btrace "python -c \"import os;os.statvfs('.')\"" -c "statvfs*|getret"
...
0.055871 statvfs@GLIBC_2.2.5/0x7f3773652bd0(0x7f37730464d0,0x7ffdbdb5ead0,0x0,0x4134e3,0x0,0x38) [/usr/lib/x86_64-linux-gnu/libc-2.31.so]
0.055882 statvfs@GLIBC_2.2.5[RET]=0x0(0)/0.000012 -> 0x45e6e8/0x400000 [/usr/bin/python3.8]
0.058732 +++ exited python(1282301) with 0 +++
root@osdc:/home/peacelee/guider/guider# ./guider.py btrace "python -c \"import os;os.statvfs('.')\"" -c "statvfs*|getret" -q completecall
...
0.055787 statvfs@GLIBC_2.2.5(0x7fa1344f64d0,0x7ffec405e320,0x0,0x4134e3,0x0,0x38)[/usr/lib/x86_64-linux-gnu/libc-2.31.so]=0x0(0)/0.000010 -
0.058247 +++ exited python(1282306) with 0 +++
What do you think about this?
- Both Python command examples succeeded also on my system (in principle). I wonder why the output was truncated for the combined analysis data by such test runs. Should any line length limitations be accordingly reconsidered?
- How will the situation be clarified further for the usage of the function “statvfs64” (by C++ programming interfaces)?
Both Python command examples succeeded also on my system (in principle). I wonder why the output was truncated for the combined analysis data by such test runs. Should any line length limitations be accordingly reconsidered?
You can use -q option such below commands.
$ ./guider.py btrace "ls" -q nocut
$ ./guider.py btrace "ls" -c "*|getret" -q completecall, nocut
How will the situation be clarified further for the usage of the function “statvfs64” (by C++ programming interfaces)?
I wonder your test program called statvfs64 really?
https://docstore.mik.ua/manuals/hp-ux/en/B2355-60130/statvfs.2.html
The field f_size contains the size of file system in f_frsize units.
Note that this field is not part of the standard POSIX definition of statvfs.
When a 32-bit application uses statvfs64() with a large file system,
f_size will top out at MAXINT, rather than return an EOVERFLOW error.
Use f_blocks instead. https://docstore.mik.ua/manuals/hp-ux/en/B2355-60130/statvfs.2.html
./guider.py btrace "ls" -c "*|getret" -q completecall, nocut
Should data truncation be avoided by default?
I wonder your test program called statvfs64 really?
It is used also by the function “QStorageInfoPrivate::retrieveVolumeInfo” for example.
How do you think about to compare test results with any data from other available analysis tools?
Example:
[Markus_Elfring@fedora ~]$ uftrace --data=Test/QStorageInfo-setPath/Probe-uftrace report --filter=statvfs64
Total time Self time Calls Function
========== ========== ========== ====================
5.585 ms 5.585 ms 1 __x64_sys_exit_group
9.565 us 1.711 us 1 statvfs64
7.440 us 7.440 us 1 __x64_sys_statfs
0.209 us 0.209 us 1 exit_to_user_mode_prepare
0.205 us 0.205 us 1 syscall_exit_to_user_mode_prepare
I can't build Qt program ;( Could you share your program binary built statically.
did you get the result of uftrace today? just statvfs can be called if QT_LARGEFILE_SUPPORT is not defined.
# if defined(QT_LARGEFILE_SUPPORT)
--
# define QT_STATFSBUF struct statvfs64
# define QT_STATFS ::statvfs64
# else
# define QT_STATFSBUF struct statvfs
# define QT_STATFS ::statvfs
# endif // QT_LARGEFILE_SUPPORT
please use a below option.
-c "statvfs*|getret"
I can't build Qt program
It seems that the software distribution dependencies can become more challenging then. May I dare to “teach” you any further possibilities (by video conferences)?
Could you share your program binary?
I can eventually offer my executable file (1 MiB with debug data) as a compressed attachment for a private mail. I am unsure if it will run in your test environment because of referenced shared library versions.
did you get the result of uftrace today?
I can refresh selected analysis data on demand.
just statvfs can be called if QT_LARGEFILE_SUPPORT is not defined.
I would like to benefit from the support of large files (also by Qt interfaces).
please use a below option.
[Markus_Elfring@fedora guider]$ ./guider.py btrace "python -c \"import os;os.statvfs('.')\"" -c 'statvfs*|getret' -q completecall,nocut
… ver_3.9.8_211002 on python_3.9
…
0.480995 statvfs@GLIBC_2.2.5(0x7fef265f7e90,0x7ffffcb638a0,0x0,0x0,0x0,0x556cd2847180)[/usr/lib64/libc-2.33.so]=0x0(0)/0.000012 -> 0x1fffa0/0x7fef33f80000 [/usr/lib64/libpython3.9.so.1.0]
0.497781 +++ exited python(13386) with 0 +++
Is another test result interesting?
[Markus_Elfring@fedora guider]$ ./guider.py btrace '/home/altes_Heim2/elfring/Projekte/Bau/QStorageInfo-setPath/QStorageInfo-setPath' -c 'statvfs*|getret' -q completecall,nocut
…
1.798169 statvfs@GLIBC_2.2.5(0x7fe92530f2b7,0x7ffe789e0780,0x0,0x7fe925db2ac0,0x1bb2630,0x0)[/usr/lib64/libc-2.33.so]=0x0(0)/0.000112 -> 0x7110/0x7fe9252ef000 [/usr/lib64/libselinux.so.1]"3 15:32:53.876" Determining file system: "/home/Markus_Elfring/gui_rpc_auth.cfg"
1.824860 statvfs@GLIBC_2.2.5(0x1bcf3b8,0x7ffe789e01b0,0x1bcf3a0,0xa,0x1bd0732,0x0)[/usr/lib64/libc-2.33.so]=0x0(0)/0.000049 -> 0x255670/0x7fe92618b000 [/usr/lib64/libQt5Core.so.5.15.2]"3 15:32:53.918" | "Data determination by setPath()" | 8085252 |ns
"3 15:32:53.922" type name: "ext4"
1.834711 +++ exited QStorageInfo-se(13775) with 0 +++
May I expect the output of line breaks for data rows?
I think I can't use your dynamic built binary in my system ;)
I guess the second statvfs() call in your last test result is it that you expected as statvfs64().
May I expect the output of line breaks for data rows?
is it right as default option? if -q NOCUT option is default then the terminal will be getting little bit dirty.
I guess the second statvfs() call in your last test result is it that you expected as statvfs64().
- How do you think about to clarify the algorithm for the lookup and checking of function names?
- Would you take any aliases into account?
if -q NOCUT option is default then the terminal will be getting little bit dirty.
- Our understanding of desirable software behaviour is occasionally different, isn't it?
- I am looking for clearer separation of data output even if text lines would be “mixed” from the parallel program execution.
How do you think about to clarify the algorithm for the lookup and checking of function names?
I found that stavfs and statvfs64 have WEEK symbols and are sharing the same address. I need to study about this :)
root@osdc:/home/peacelee/guider/guider# readelf -a /usr/lib/x86_64-linux-gnu/libc.so.6 | grep statvfs
288: 0000000000110bd0 116 FUNC WEAK DEFAULT 16 statvfs64@@GLIBC_2.2.5
648: 0000000000110bd0 116 FUNC WEAK DEFAULT 16 statvfs@@GLIBC_2.2.5
718: 0000000000110c50 108 FUNC WEAK DEFAULT 16 fstatvfs@@GLIBC_2.2.5
1633: 0000000000110c50 108 FUNC WEAK DEFAULT 16 fstatvfs64@@GLIBC_2.2.5
I am looking for clearer separation of data output even if text lines would be “mixed” from the parallel program execution.
I agree with this. Using "-o" option will make Guider to save it's all output to the specific per-task file without any strip. isn't it enough?
I need to study about this
I am curious on further collateral evolution.
isn't it enough?
I became curious also about the order for writing line breaks for data rows.
I am curious on further collateral evolution.
There is no difference between statvfs() and statvfs64() in my x86_64 system. Have you tested it on 32bit system?
I became curious also about the order for writing line breaks for data rows.
- check the length of a string line when printing.
- It will be cut if only it is longer than the width of terminal except when output file is set.
There is no difference between statvfs() and statvfs64() in my x86_64 system.
- I hope that further software analyses will become supported for both function names.
- Would you like to check consequences any more for aliases?
Have you tested it on 32bit system?
I find that this technical detail should not matter for the desired clarification at the moment (also according to a function call report by the tool “uftrace”).
It will be cut if only it is longer than the width of terminal except when output file is set.
- I propose to reconsider case distinctions for data truncation.
- Will each data row be written with a line break at the end?
- Are file flushes applied here?
- Will any improvements help for the involved software documentation?