Writing fp-info-cache temp file take too long over networked FS (e.g. samba)

Bug #1855562 reported by aaa
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
kicad (Ubuntu)
New
Undecided
Unassigned

Bug Description

Hi,

Application: Pcbnew
Version: 5.1.5-52549c5~84~ubuntu18.04.1, release build
Libraries:
    wxWidgets 3.0.4
    libcurl/7.58.0 OpenSSL/1.1.1 zlib/1.2.11 libidn2/2.0.4 libpsl/0.19.1 (+libidn2/2.0.4) nghttp2/1.30.0 librtmp/2.3
Platform: Linux 4.15.0-20-generic x86_64, 64 bit, Little endian, wxGTK
Build Info:
    wxWidgets: 3.0.4 (wchar_t,wx containers,compatible with 2.8) GTK+ 3.22
    Boost: 1.65.1
    OpenCASCADE Community Edition: 6.9.1
    Curl: 7.58.0
    Compiler: GCC 7.4.0 with C++ ABI 1011

Build settings:
    USE_WX_GRAPHICS_CONTEXT=OFF
    USE_WX_OVERLAY=ON
    KICAD_SCRIPTING=ON
    KICAD_SCRIPTING_MODULES=ON
    KICAD_SCRIPTING_PYTHON3=ON
    KICAD_SCRIPTING_WXPYTHON=ON
    KICAD_SCRIPTING_WXPYTHON_PHOENIX=ON
    KICAD_SCRIPTING_ACTION_MENU=ON
    BUILD_GITHUB_PLUGIN=ON
    KICAD_USE_OCE=ON
    KICAD_USE_OCC=OFF
    KICAD_SPICE=ON

When closing either Footprint Editor or pcbnew, fp-info-cache<random> temp file is written from scratch line-by-line into the project's directory. This is fine when the project directory is on a local filesystem. However, if the project directory is on a samba share, writing the whole file can take literally a minute. This means that the application window is not refreshing and it seems like it hung. This is annoying when you are editing a footprint and forget about this behaviour and 'accidentally' close the footprint editor. You have to wait a minute for the fp-info-cache<random> file to get completely written before you can continue working with kicad.

Looking at the samba server logs, the fp-info-cache<random> is written line by line and each write is sent as a separate request:

[2019/12/07 23:18:11.740618, 3] ../source3/smbd/smb2_write.c:212(smb2_write_complete_internal)
  smb2: fnum 2023785553, file plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY, length=2 offset=0 wrote=2
[2019/12/07 23:18:11.741681, 3] ../source3/smbd/smb2_write.c:212(smb2_write_complete_internal)
  smb2: fnum 2023785553, file plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY, length=2 offset=0 wrote=2
[2019/12/07 23:18:11.742641, 3] ../source3/smbd/smb2_write.c:212(smb2_write_complete_internal)
  smb2: fnum 2023785553, file plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY, length=9 offset=0 wrote=9
[2019/12/07 23:18:11.744346, 3] ../source3/smbd/smb2_write.c:212(smb2_write_complete_internal)
  smb2: fnum 2023785553, file plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY, length=30 offset=0 wrote=30
[2019/12/07 23:18:11.745263, 3] ../source3/smbd/smb2_write.c:212(smb2_write_complete_internal)
  smb2: fnum 2023785553, file plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY, length=52 offset=0 wrote=52
[2019/12/07 23:18:11.746235, 3] ../source3/smbd/smb2_write.c:212(smb2_write_complete_internal)
  smb2: fnum 2023785553, file plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY, length=14 offset=0 wrote=14
[2019/12/07 23:18:11.747096, 3] ../source3/smbd/smb2_write.c:212(smb2_write_complete_internal)
  smb2: fnum 2023785553, file plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY, length=2 offset=0 wrote=2

In general, writing one fp-info-cache<random> file, with the default set of footprint libraries, can produce ~75k individual writes over the network, in this case:

[ /var/log/samba ]# cat log. | grep fp-info-cache0bIzQY | grep wrote | wc -l
75048
[ /var/log/samba ]# wc -l /mnt/data/ostatne/plosaky/polizei_rx/polizei_rx/fp-info-cache
75048 /mnt/data/ostatne/plosaky/polizei_rx/polizei_rx/fp-info-cache

..and take more than a minute:

[/var/log/samba ]# cat log. | grep fp-info-cache0bIzQY -B1 | head -2
[2019/12/07 23:16:56.293527, 2] ../source3/smbd/open.c:1006(open_file)
  peter opened file plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY read=Yes write=Yes (numopen=1)
[ /var/log/samba ]# cat log. | grep fp-info-cache0bIzQY -B1 | tail -2
[2019/12/07 23:18:12.022399, 3] ../source3/smbd/reply.c:6777(rename_internals_fsp)
  rename_internals_fsp: succeeded doing rename on plosaky/polizei_rx/polizei_rx/fp-info-cache0bIzQY -> plosaky/polizei_rx/polizei_rx/fp-info-cache

I have not find a way to fine tune the samba server/client to improve the write times. I believe there is not a way to do it, since the file is written line-by-line as separate write requests.

Is there a better way for kicad to write the fp-info-cache<random> file?

Perhaps writing the fp-info-cache<random> file first into an OS temp directory (assuming the OS temp dir is almost always on a local drive, thus very fast) and then, once the fp-info-cache<random> file is completely written in the temp directory, copy the file from the temp dir ectory to the project's directory? The copy operation would be done in a few (one?) network file system write command(s).

Thanks,
Peter

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.