NullPointerException when reading cache file

[chrthi]

When opening a cache file generated with the qdirstat-cache-writer script, qdirstat starts displaying the directory tree and then terminates with a NullPointerException. Backtrace:

#0  0x00007ffff54ad107 in raise () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#1  0x00007ffff54ae4e8 in abort () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#2  0x00007ffff5d98b3d in __gnu_cxx::__verbose_terminate_handler() () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
No symbol table info available.
#3  0x00007ffff5d96bb6 in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
No symbol table info available.
#4  0x00007ffff5d96c01 in std::terminate() () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
No symbol table info available.
#5  0x00007ffff5d96e19 in __cxa_throw () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
No symbol table info available.
#6  0x0000000000418e8a in _throw_helper<NullPointerException> (exception=..., logger=0x0, srcFile=..., srcLine=486, 
    srcFunction=...) at Exception.h:288
No locals.
#7  0x0000000000446682 in QDirStat::DirTreeModel::index (this=0x7edc90, row=23, column=0, parentIndex=...)
    at DirTreeModel.cpp:486
        parent = 0xd31270
        __FUNCTION__ = "index"
        child = 0x0
#8  0x00007ffff77394c1 in QTreeViewPrivate::layout(int, bool, bool) () from /usr/lib/x86_64-linux-gnu/libQt5Widgets.so.5
No symbol table info available.
#9  0x00007ffff7739db6 in QTreeView::expandToDepth(int) () from /usr/lib/x86_64-linux-gnu/libQt5Widgets.so.5
No symbol table info available.
#10 0x0000000000455ad3 in MainWindow::expandTreeToLevel (this=0x7fffffffe100, level=1) at MainWindow.cpp:516
No locals.
#11 0x0000000000454d2d in MainWindow::idleDisplay (this=0x7fffffffe100) at MainWindow.cpp:394
        sortCol = 32767
#12 0x0000000000454e25 in MainWindow::readingFinished (this=0x7fffffffe100) at MainWindow.cpp:412
        __FUNCTION__ = "readingFinished"
(More stack frames follow...)

The cache file is from a separate machine, so the actual directory structure is not accessible for qdirstat. The same cache file works fine when opened in k4dirstat after changing the header to [kdirstat 4.0 cache file]. Unfortunately, I can't share this particular cache file and haven't yet managed to reproduce this error on another file.
It might also be interesting that according to the logfile, the last child is <Files>:

2016-01-17 15:09:56.268 [1264] <ERROR>   DirTreeModel.cpp:180 findChild():  Child #23 is out of range: 0..22 children for /hom
e/freak/
2016-01-17 15:09:56.268 [1264] <Debug>   DebugHelpers.cpp:55 dumpChildrenList():  Children of /home/freak/
...
2016-01-17 15:09:56.269 [1264] <Debug>   DebugHelpers.cpp:59 dumpChildrenList():      #22: /home/freak//<Files>
2016-01-17 15:09:56.269 [1264] <WARNING> DirTreeModel.cpp:486 index():  THROW Exception: Null pointer

If I can do something more to help investigate this, please let me know.

[shundhammer]

Hm... the tree view requesting child #23 when there are only 0..22 is kind of weird. After all, the DirTreeModel told him in rowCount() how many children there are.

One thing I could imagine is that there are no plain files on that directory level, only subdirectories. In that case, in a final step (finalizeLocal()) the parent directory cleans up the unused "Files" item (the "dot entry"), which means that from that point on there is one less child on that level - that dot entry was deleted.

Does that sound likely in your scenario? Only subdirectories on that directory level, no files?
Or even the other way round: No subdirectories, only files?

[chrthi]

No, the top directory has both subdirectories and files in it. But the last entry in the cache file is a directory without files. I'll try playing with the cache file to see if I can narrow down the reason or anonymize and send it as soon as I have time.

[oliver]

I have the same problem here (qdirstat crashes with NullPointerException from QDirStat::DirTreeModel::index(), and logs message like Child #3 is out of range: 0..2 children for /export/work/og/). Unfortunately I can't share the cache file either.

In my case, the cache file can be read with k4dirstat, but at closer look it is actually displayed incorrectly in k4dirstat - there are lots of top-level directories missing, and total data size is way off. That bug is actually the reason why I've looked at qdirstat at all :-)

The cache file was created with /home/og/bin/kdirstat-cache-writer.pl /export/work/og/. When reading that cache file in qdirstat, the crash happens for the top-level directory, which contains several directories, one symlink, and several normal files.

Btw. the cache file contains pathes with double slashes, like this: D /export/work/og//kde-og 4096 0x44a3f57a.
Not sure if that makes a difference.

[shundhammer]

Hm - maybe the double slashes really have something to do with this. It's a remote possibility, but it's a hint.

I'll try to reproduce the problem with this scenario. If it's just a double-slash problem, it should be easy enough to fix.

[shundhammer]

Looks like I found a way to reproduce this, albeit not with a double slash ("//") path:

2016-02-01 14:26:17.773 [12441] DirTreeModel.cpp:180 findChild(): Child #2 is out of range: 0..1 children for /space/shundhammer
2016-02-01 14:26:17.773 [12441] DebugHelpers.cpp:55 dumpChildrenList(): Children of /space/shundhammer
2016-02-01 14:26:17.773 [12441] DebugHelpers.cpp:59 dumpChildrenList(): #0: /space/shundhammer/src
2016-02-01 14:26:17.773 [12441] DebugHelpers.cpp:59 dumpChildrenList(): #1: /space/shundhammer/
2016-02-01 14:26:17.773 [12441] DirTreeModel.cpp:488 index(): THROW Exception: Null pointer

Do you guys also have a lot of "could not locate parent" messages in the log?

2016-02-01 14:26:17.760 [12441] DirTreeCache.cpp:404 addItem(): /tmp/qdirstat.cache.gz:118556: Could not locate parent /space/shundhammer/obs/YaST:Head
2016-02-01 14:26:17.760 [12441] DirTreeCache.cpp:404 addItem(): /tmp/qdirstat.cache.gz:118557: Could not locate parent _project
2016-02-01 14:26:17.760 [12441] DirTreeCache.cpp:404 addItem(): /tmp/qdirstat.cache.gz:118558: Could not locate parent _apiurl
2016-02-01 14:26:17.760 [12441] DirTreeCache.cpp:404 addItem(): /tmp/qdirstat.cache.gz:118559: Could not locate parent _packages
2016-02-01 14:26:17.760 [12441] DirTreeCache.cpp:404 addItem(): /tmp/qdirstat.cache.gz:118560: Could not locate parent _build_repositories

[oliver]

Great to hear that you could repro such a crash!

However, there are no could not locate parent messages in my log. Here is the qdirstat log for such a crash:

2016-02-01 14:37:37.047 [11241] <Info>    Logger.cpp:74 Logger():  -- Log Start --
2016-02-01 14:37:38.031 [11241] <Debug>   TreemapView.cpp:42 TreemapView():  
2016-02-01 14:37:38.273 [11241] <Debug>   DirTreeModel.cpp:521 sort():  Sorting by NameCol ascending
2016-02-01 14:37:38.273 [11241] <Debug>   TreemapView.cpp:113 setSelectionModel():  
2016-02-01 14:37:38.276 [11241] <WARNING> Cleanup.cpp:396 desktopSpecificApps():  $XDG_CURRENT_DESKTOP is not set - using fallback apps
2016-02-01 14:37:38.276 [11241] <Info>    Cleanup.cpp:454 desktopSpecificApps():  %filemanager => "xdg-open"
2016-02-01 14:37:38.276 [11241] <Info>    Cleanup.cpp:454 desktopSpecificApps():  %terminal => "xterm"
2016-02-01 14:37:38.277 [11241] <Debug>   DebugHelpers.cpp:133 dumpExcludeRules():  <ExcludeRule ".snapshot">
2016-02-01 14:37:38.277 [11241] <Info>    MainWindow.cpp:717 toggleVerboseSelection():  Verbose selection is now off. Change this with Shift-F7.
2016-02-01 14:37:50.531 [11241] <Debug>   DirTreeModel.cpp:521 sort():  Sorting by PercentBarCol descending
2016-02-01 14:37:50.531 [11241] <Debug>   DirTreeModel.cpp:536 sort():  Sorting by ReadJobsCol during reading
2016-02-01 14:37:50.738 [11241] <Debug>   MainWindow.cpp:527 expandTreeToLevel():  Expanding tree to level 1
2016-02-01 14:37:54.578 [11241] <Debug>   DirTreeCache.cpp:228 ~CacheReader():  Cache reading finished
2016-02-01 14:37:54.610 [11241] <Debug>   DirTreeCache.cpp:237 ~CacheReader():  Sending read job finished for /export/work/og/
2016-02-01 14:37:54.634 [11241] <Info>    MainWindow.cpp:424 readingFinished():  
2016-02-01 14:37:54.634 [11241] <ERROR>   DirTreeModel.cpp:180 findChild():  Child #3 is out of range: 0..2 children for /export/work/og/
2016-02-01 14:37:54.634 [11241] <Debug>   DebugHelpers.cpp:55 dumpChildrenList():  Children of /export/work/og/
2016-02-01 14:37:54.634 [11241] <Debug>   DebugHelpers.cpp:59 dumpChildrenList():      #0: /export/work/og/censored
2016-02-01 14:37:54.634 [11241] <Debug>   DebugHelpers.cpp:59 dumpChildrenList():      #1: /export/work/og/kde-og
2016-02-01 14:37:54.634 [11241] <Debug>   DebugHelpers.cpp:59 dumpChildrenList():      #2: /export/work/og//<Files>
2016-02-01 14:37:54.634 [11241] <WARNING> DirTreeModel.cpp:488 index():  THROW Exception: Null pointer

I created this log by starting src/qdirstat, cancelling the Directory Chooser Dialog (since reading the desired directory takes ages), and using File -> Read Cache File to open /export/work/og/.kdirstat.cache.gz directly. The treeview displayed the top-level entry and three children (there should be like 100 child directories), and then crashed.

Edit: Btw. what did you do to get the crash?

[shundhammer]

I used a really large cache file - large enough for the tree widget to try to display something while cache reading was still in progress.

[shundhammer]

Please test again with the latest version which includes 5354e0b

This should fix the problem.

Background: While directories are being read, only finished directories are reported to the tree view by the data model so the view doesn't get confused by partially read directories. Otherwise the model would have to keep track what parts of the directory tree it already reported to which view (there might be any number of views connected to it) and report delta information (what's new) individually. Whenever a view requests information from the model, the model returns "0 items on this level" while a directory is being read, i.e. it has read state DirReading.

With cache files, that status used to be set to "DirCached" immediately, yet it could happen just as well that a directory was only partially read - albeit much less frequently because the chunks in which cache files are read are pretty large, and today's hardware is really fast at simple text processing.

Now, the read status remains at DirQueued for all those cached directories until the very last moment: In the destructor of the CacheReader all directories in the cache are "finalized" at the same time, i.e. their read state is set to DirCached and empty or unneded "" items ("dot entries") are removed.

Thus, there is no more time gap during which the data model releases premature information to the view(s); it's all from zero to complete in an instant.

[shundhammer]

chrti, oliver, please test with this fix at your earliest convenience and write a note here if this really fixes the problem. I sure hope so. ;-)

[oliver]

Your fix works for me - qdirstat no longer crashes! Thanks a lot for the quick response!
My cache file has some million lines and lots of deep directory structures, so this race condition will quite likely be hit.

The directory list read from cache file is still displayed incompletely (as it was in kdirstat), but I'll open a separate ticket for that.

[shundhammer]

During debugging this, I found that there seems to be a problem with directories that have a colon ":" in their name. I suspect some URL escape or unescape function might be a problem here. With a little bit of luck, I can find some time today or in the next few days to address this.

BTW that seems to be the reason for those "Could not locate parent" errors I mentioned: One of their ancestor directories had a name like "YaST:Head".

[chrthi]

Your fix works for me too - I tried the commit you mentioned and its parent; my cache file crashes the older version, but not the one with the fix. Good job!

[shundhammer]

OK, thanks for the feedback!