Skip to content

Generate system performance data for performance related issues

abraunegg edited this page Oct 14, 2022 · 4 revisions

In some cases it may be necessary to generate system performance data to assist further with analysing what is occuring. Use the following details to generate the performance details:

Prerequisite

Rebuild your client to support debug symbols:

git clone https://github.com/abraunegg/onedrive.git
cd onedrive
./configure --enable-debug
make clean; make;
sudo make install

Install the application including any debug symbols generated. You may also need to install your Linux Kernel Debug Symbols as well.

Performance data to collect

Client Function Performance data

Run the client with the following option set in your 'config' file:

display_processing_time = "true"

This will print important performance related processing timings for each major function the application performs, which will help to drill down what function is potentially causing your performance concern.

At the end of a sync cycle, also take note of the following data point:

Total number of OneDrive items processed: XXXXXXXX

Microsoft recommends storing no more that 300,000 files & folders in a single OneDrive account. If you are getting up towards this number, how and what you store on OneDrive needs to be looked at first.

Secondly, if you are storing items close to this value online, it is going to take time to process this data when performing a full sync. OneDrive sends data to this client in ~200 item lots as a change set (this is hardcoded by Microsoft, there is zero way to change this). A change set will take approx 1-1.5 seconds for this client to process depending on how many items are present in the change set.

Example: If you have 200k items on OneDrive, this means approx 1000 change set bundles will be sent to the client. Assuming 1.5 seconds to process each one = 1500 seconds = 25 minutes to process your online data.

You can adjust when a 'full scan' is performed by adjusting the following 'config' options:

CPU Information

cat /proc/cpuinfo

Memory Information

cat /proc/meminfo   

CPU Performance Governance

cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_governors
cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor 

Disk I/O

Run for at least ~30 minutes:

iostat -dx 2

Generate an strace

Run strace on the application as it is running:

  • ps -AL |grep process_name
  • strace -c -p <PID>

Example:

[alex@centos7full ~]$ ps -AL | grep onedrive
16753 16753 pts/0    00:00:00 onedrive
[alex@centos7full ~]$ strace -c -p 16753
strace: Process 16753 attached
^Cstrace: Process 16753 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 20.98    0.000823          16        53           nanosleep
 17.31    0.000679         679         1           open
 17.23    0.000676         169         4           sendto
 13.61    0.000534         178         3           stat
 10.32    0.000405           4       102           fcntl
  8.56    0.000336           4        87           poll
  3.77    0.000148           4        38           write
  3.24    0.000127          32         4           fsync
  1.33    0.000052           2        23           lseek
  0.97    0.000038           2        16           recvfrom
  0.59    0.000023          12         2           close
  0.54    0.000021          21         1           unlink
  0.46    0.000018           9         2           read
  0.41    0.000016           8         2         1 access
  0.25    0.000010           3         4           fstat
  0.18    0.000007           7         1           restart_syscall
  0.10    0.000004           2         2           getdents
  0.10    0.000004           4         1           openat
  0.05    0.000002           1         4           lstat
------ ----------- ----------- --------- --------- ----------------
100.00    0.003923                   350         1 total

Generate system performance profile

Run perf on the application as it is running:

  • ps -AL |grep process_name
  • perf top --call-graph dwarf --pid <PID>

Example:

-   95,99%     0,00%  onedrive  [unknown]                   [k] 0xffffffffffffffff                                                        ◆
   - 0xffffffffffffffff                                                                                                                   ▒
      - 61,14% _D4sync10SyncEngine17uploadDifferencesMFS6itemdb4ItemZv                                                                    ▒
           _D4sync10SyncEngine20uploadDirDifferencesMFS6itemdb4ItemAyaZv                                                                  ▒
           _D4sync10SyncEngine17uploadDifferencesMFS6itemdb4ItemZv                                                                        ▒
           _D4sync10SyncEngine20uploadDirDifferencesMFS6itemdb4ItemAyaZv                                                                  ▒
         - _D4sync10SyncEngine17uploadDifferencesMFS6itemdb4ItemZv                                                                        ▒
            - 61,13% _D4sync10SyncEngine20uploadDirDifferencesMFS6itemdb4ItemAyaZv                                                        ▒
               - 61,13% _D4sync10SyncEngine17uploadDifferencesMFS6itemdb4ItemZv                                                           ▒
                  - 61,09% _D4sync10SyncEngine20uploadDirDifferencesMFS6itemdb4ItemAyaZv                                                  ▒
                     - 61,08% _D4sync10SyncEngine17uploadDifferencesMFS6itemdb4ItemZv                                                     ▒
                        - 61,03% _D4sync10SyncEngine20uploadDirDifferencesMFS6itemdb4ItemAyaZv                                            ▒
                             _D4sync10SyncEngine17uploadDifferencesMFS6itemdb4ItemZv                                                      ▒
                             _D4sync10SyncEngine20uploadDirDifferencesMFS6itemdb4ItemAyaZv                                                ▒
                             _D4sync10SyncEngine17uploadDifferencesMFS6itemdb4ItemZv                                                      ▒
                           - _D4sync10SyncEngine20uploadDirDifferencesMFS6itemdb4ItemAyaZv                                                ▒
                              - 60,65% _D6itemdb12ItemDatabase14selectChildrenMFAxaQdZASQBv4Item                                          ▒
                                 - 41,31% _D6sqlite9Statement6Result4stepMFZv                                                             ▒
                                      sqlite3_step                                                                                        ▒
                                      sqlite3Step (inlined)                                                                               ▒
                                    - sqlite3VdbeExec                                                                                     ▒
                                       - 41,31% sqlite3VdbeCursorMoveto (inlined)                                                         ▒
                                            handleDeferredMoveto                                                                          ▒
                                            sqlite3BtreeMovetoUnpacked                                                                    ▒
                                            getAndInitPage                                                                                ▒
                                            sqlite3PagerGet (inlined)                                                                     ▒
                                            getPageNormal                                                                                 ▒
                                          - readDbPage                                                                                    ▒
                                             - 39,74% sqlite3OsRead (inlined)                                                             ▒
                                                - unixRead                                                                                ▒
                                                   - seekAndRead (inlined)                                                                ▒
                                                      - __libc_pread64                                                                    ▒
                                                         - 32,17% entry_SYSCALL_64                                                        ▒
                                                            - 31,72% do_syscall_64                                                        ▒
                                                               - 29,92% sys_pread64                                                       ▒
                                                                  - 27,99% vfs_read                                                       ▒
                                                                     - 26,21% __vfs_read                                                  ▒
                                                                        - 26,08% new_sync_read                                            ▒
                                                                           - 25,84% ext4_file_read_iter                                   ▒
                                                                              - 25,38% generic_file_read_iter                             ▒
                                                                                 - 17,04% copy_page_to_iter                               ▒
                                                                                      16,57% copy_user_enhanced_fast_string               ▒
                                                                                 + 6,41% pagecache_get_page                               ▒
                                                                     + 1,26% rw_verify_area                                               ▒
                                                                  + 1,26% __fdget                                                         ▒
                                                                 0,75% syscall_trace_enter                                                ▒
                                                                 0,64% syscall_slow_exit_work                                             ▒
                                                           3,61% syscall_return_via_sysret                                                ▒
                                                           2,33% 0xfffffe000016601b                                                       ▒
                                               1,09% sqlite3WalFindFrame                                                                  ▒
                                 + 19,34% _D6sqlite9Statement4execMFZSQBaQw6Result                                                        ▒

Performance Data Submission