GNOME Bugzilla – Bug 168414
xmlParseFile: three stats and one open
Last modified: 2021-07-05 13:25:03 UTC
When parsing a pretty simple file like gnumeric's fn-random/plugin.xml (to be attached), libxml2 stats it three times before opening. That adds up when used over many files. Suggestions in order of preference: 1. Don't stat at all. 2. Don't stat, but fstat. 3. Stat only once. # Version information for libxml2. current=8 age=6 revision=11
Created attachment 37907 [details] fn-random/plugin.xml
and the traces... > #1 0xfacd625c in xmlSysIDExists (URL=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > xmlIO.c:3359 > #2 0xfacd64ec in xmlLoadExternalEntity (URL=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > ID=0x0, ctxt=0x48bb30) at xmlIO.c:3512 > #3 0xfacc57c8 in xmlCreateURLParserCtxt (filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > options=0) at parser.c:11138 > #4 0xfacc5838 in xmlCreateFileParserCtxt (filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > parser.c:11166 > #5 0xfacc5860 in xmlSAXParseFileWithData (sax=0x0, filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > recovery=0, data=0x0) at parser.c:11198 > #6 0xfacc59a8 in xmlSAXParseFile (sax=0x0, filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > recovery=0) at parser.c:11260 > #7 0xfacc59e0 in xmlParseFile (filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > parser.c:11291 > #8 0x162600 in plugin_info_read (plugin=0x449ca8, dir_name=0x449d80 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random", > ret_error=0xffbee694) at go-plugin.c:711 ----------------------------------------------------------------------------- > #1 0xfacd625c in xmlSysIDExists (URL=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > xmlIO.c:3359 > #2 0xfacd62d8 in xmlDefaultExternalEntityLoader (URL=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > ID=0x0, ctxt=0x48bb30) at xmlIO.c:3407 > #3 0xfacd657c in xmlLoadExternalEntity (URL=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > ID=0x0, ctxt=0x48bb30) at xmlIO.c:3526 > #4 0xfacc57c8 in xmlCreateURLParserCtxt (filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > options=0) at parser.c:11138 > #5 0xfacc5838 in xmlCreateFileParserCtxt (filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > parser.c:11166 > #6 0xfacc5860 in xmlSAXParseFileWithData (sax=0x0, filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > recovery=0, data=0x0) at parser.c:11198 > #7 0xfacc59a8 in xmlSAXParseFile (sax=0x0, filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > recovery=0) at parser.c:11260 > #8 0xfacc59e0 in xmlParseFile (filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > parser.c:11291 > #9 0x162600 in plugin_info_read (plugin=0x449ca8, dir_name=0x449d80 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random", > ret_error=0xffbee694) at go-plugin.c:711 ----------------------------------------------------------------------------- > #1 0xfacd30d4 in xmlCheckFilename (path=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > xmlIO.c:557 > #2 0xfacd3660 in xmlGzfileOpen_real (filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > xmlIO.c:898 > #3 0xfacd36ac in xmlGzfileOpen (filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > xmlIO.c:917 > #4 0xfacd4a2c in __xmlParserInputBufferCreateFilename (URI=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > enc=XML_CHAR_ENCODING_NONE) at xmlIO.c:2147 > #5 0xfacd4b80 in xmlParserInputBufferCreateFilename (URI=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml", > enc=XML_CHAR_ENCODING_NONE) at xmlIO.c:2207 > #6 0xfacaeb34 in xmlNewInputFromFile (ctxt=0x48bb30, filename=0x48baa8 > "/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/fn-random/plugin.xml") at > parserInternals.c:1463
Let's be frank. I consider this really low priority. Removing the stat() calls without changing the behaviour of the catalog handling is not gonna be trivial at all, maybe the information from the first stat() can be cached for the second. Maybe the xmlGzfileOpen should not stat, how much of a hazard it is gonna introduce on weird platform is completely unclear to me. Further questions to evaluate the priority of your request: 1/ what is the cost of calling stat() once versus 3 times. On Linux the dentry cache should bring this back to the cost of the first stat() and twice the cost of an empy syscall, so basically either removing all calls is useful, but removing the subsequent ones is chasing picoseconds, i.e. useless in practice. 2/ can you justify why stat() versus fstat() makes such a difference in speed Daniel
There are actually two issues here: correctness and speed. Correctness: there is no guarantee that the stat calls and the open call refer to the same file. If you rely on that, you have a race condition. With fstat, on the other had, there is just one file. Speed: You are *eight* orders of magnitude off! When you stat, the kernel /has/to/walk/the/whole/tree/again. With mountpoints, remote filesystems, and the need to update access times, that comes out as .3ms for each of the non-first stat calls. With 105 calls that adds up to about 5% of my start time. troll:~> grep stat64 ~/xxx | grep plugin | head -3 0.0010 stat64("/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/plot_pie/plugin.xml", 0xFFBEE2D8) = 0 0.0004 stat64("/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/plot_pie/plugin.xml", 0xFFBEE268) = 0 0.0006 stat64("/home/welinder/gnome/lib/gnumeric/1.5.1/plugins/plot_pie/plugin.xml", 0xFFBEE030) = 0 troll:~> grep stat64 ~/xxx | grep plugin | wc -l 105 troll:~> grep stat64 ~/xxx | grep plugin | perl -ne 'my ($time,$filename) = /^(.*)stat64."(.*)"/; next unless $seen{$filename}++; $sum += $time; $count++; END { print $sum/$count, "\n"; }' 0.000331428571428572 (Timings for Solaris, btw.)
I use stat() to find out if the file exists. If it doesn't exist it may mean one need to use a catalog, or that some %20 need to be URI-unescaped. Of course the APIs do *NOT* allows to open() and pass the fd down. Especially at the catalog level. So fstat() being faster than stat() is well useless to me in that case. I doubt anybody would prefer open()/fstat()/close() for this. trying an open() first and falling back to unescaping might work or just plain break the catalog stuff. I need to be able to check wether a file exists or not for catalog handling. if someone removes the files or the catalog while the file is being loaded, no semantic can be guaranteed I see no point about trying to establish "correctness" in that case. Failing to open the file as well a succeeding are correct behaviour in such a situation, there is no semantic loss. So stat() is slow on Solaris, as a result I should break my catalog and filename checking code which took years to foolproof and get working on dozens of architectures ... Okay we can try that. Submit patches to the mailing list and get them reviewed. I don't have Windows boxes, and any change in that code should be tested *before the release* to make sure it doesn't break. One way to do this is to #ifndef __sun__ / #endif and check how much break in the next release for Solaris users, but of course I dislike this. But further discussions about this really need to go on the list as this is not trivial and has non-neglectible OS dependant risks. Daniel
This is not a Solaris issue: Linux timings show similar results. I am guessing that the problem is that you keep thinking stat("foo") when the call is really stat("/some/mighty/long/path/with/symlinks/and/mountpoints"). I'll take your word for stat("foo") being fast; it just isn't relevant. Note also, that fstat(2) is in itself a simple query while stat(2) initiates lots of disk writes, one per directory it passes. (Doing open+fstat+close isn't even funny.) It sounds a bit like "this is hard to fix, so it cannot be important". Well, fine, but that does put your blog in a different light. It's your library so it's your decision. A reason it isn't awfully important is that the workaround is simple: I read the file myself, then parse the memory area. That works well as the files are small, i.e., blocking and waiting for read(2) would happen anyway.
> It sounds a bit like "this is hard to fix, so it cannot be important". Well, > fine, but that does put your blog in a different light. It's your library so > it's your decision. So you're trying to put some blame on me ? It's not *my* library. It's the library of a lot of people. There is 700+ people subscribed to that list. And I did point at this *very* bug no later than 2 hours ago on the list ! http://mail.gnome.org/archives/xml/2005-April/msg00026.html Yet another "let's blame the guy", do not follow his suggestions (I asked to put that on the list you didn't bothered doing so), and it's so much easier to put the pressure on the guy than working with him ! Working with me in that case mean working with the large amount of people using this library on various OS, a number of them doing performance oriented work, this mean work in the way an open source project should work, if there is a non-trivial issue getting to the solution is a collective process. But again, yes it's so much simpler to simply blame the guy who happen to have answered your bugzilla entry. That bug is open, if my decision was "forget about it" it would be CLOSED WONTFIX. I just don't want to take risks with this. Loading of the main entity is not a problem, if you really want to bypass that part of libxml2 just open() the file and hand the fd to xmlReadFd(). That would have been the first suggestion you would have got on the list, and better than your solution since you don't have to keep the files content in memory. Your comment about a stat() issuing *write* to disk sounds completely unfounded to me, can you back it up ? I don't see how this can be compatible with a POSIX filesystem semantic ! But it's so much easier to think I'm wrong, or stupid or maybe ignorant and put comments like #6 . But my take is that you're just being unfair: - thinking I forgot about the issue - thinking I don't believe it need to be fixed - blaming me on this entry instead of following the suggestion I made on my last comment See, your comment about my blog and this bug is clearly unfounded and utterly unfair. I think you are able to do this behind the virtualization layer of an Internet communication, you would not do this face to face ! Daniel
You are seeing ghosts: no-one is blaming you (beyond the weakest of meanings, ie., that filing of any bug represents some sort of assigning blame). This isn't worth getting agitated over (on either side). Please consider this bug report retracted. Hmm... OBSOLETE seems to be closest.
Reopening, the 3 stats are still there though there have been some look at it. > You are seeing ghosts: no-one is blaming you Then I really misunderstood your comment : It sounds a bit like "this is hard to fix, so it cannot be important". Well, : fine, but that does put your blog in a different light. - how did this change light on my blog ? - what did you try to tell (me) ? Daniel
GNOME is going to shut down bugzilla.gnome.org in favor of gitlab.gnome.org. As part of that, we are mass-closing older open tickets in bugzilla.gnome.org which have not seen updates for a longer time (resources are unfortunately quite limited so not every ticket can get handled). If you can still reproduce the situation described in this ticket in a recent and supported software version, then please follow https://wiki.gnome.org/GettingInTouch/BugReportingGuidelines and create a new ticket at https://gitlab.gnome.org/GNOME/libxml2/-/issues/ Thank you for your understanding and your help.