After the initial message, conversations are not indexed or searchable until TB is restarted

RESOLVED FIXED in Thunderbird 17.0


Instant Messaging
5 years ago
5 years ago


(Reporter: mconley, Assigned: mconley)


15 Branch
Thunderbird 17.0
Windows 7

Thunderbird Tracking Flags

(thunderbird15 fixed, thunderbird16 fixed)



(1 attachment, 1 obsolete attachment)


1) Create an IRC account in TB, and join an empty channel
2) On a separate client, join the same channel
3) Chat with yourself, using words that are easy to search for.
4) Upon receiving the first message from the non-TB client, note that you can search for that message

What happens?

Subsequent messages do not appear in search results until *after* TB is restarted.

What's expected?

The messages should be indexed soon after the user sees them, and then immediately searchable without a restart.

I'm not sure if my STR are accurate - I'm still feeling this one out.
I'm experiencing this in the latest beta, and on a trunk build.
tracking-thunderbird15: --- → ?
tracking-thunderbird16: --- → ?
This bug appears to be in TB Beta build 2 as well, so this doesn't appear to be caused by the deferred Gloda indexing work I did.
Hm, so far, I'm only able to reproduce this on my Windows machine. My Linux box seems to be working fine, which makes me wonder if something's gone wrong with my Gloda index, or perhaps my IM logs...

I'll try a new profile.
Ok, I think I figured this one out.

Our IM indexer caches and compares the last modified time for each log file in order to know whether or not to re-index a log file.

The indexer does this by holding a reference to the known log files, and simply checking nsIFile.lastModifiedTime.

The problem seems to be that on Windows, the lastModifiedTime is cached at the point where the nsIFile is instantiated...whereas on Linux (and maybe OSX, I didn't check), lastModifiedTime is updated dynamically.

That means that on Windows, the lastModifiedTime never changed from the point where we first made a reference to the file, so TB thought that the logs weren't changing, and so it wasn't re-indexing the files.

My solution is to "refresh" our reference to the log files at the point of starting an index job by using nsIFile.clone. This is the workaround that rkent suggested. He's also familiar with this Gecko lastModifiedTime bug, so he might be able to answer any questions about what that's all about. I've Cc'd him.

Patch up in a minute.
OS: All → Windows 7
Created attachment 652206 [details] [diff] [review]
Patch v1

This fixes things on Windows for me.
Attachment #652206 - Flags: review?(bwinton)
Comment on attachment 652206 [details] [diff] [review]
Patch v1

So, I've got two problems with this patch.

a) It's not a patch.
b) even if it was, I am in no way qualified to review this change.


Blake.  ;)
Attachment #652206 - Flags: review?(bwinton) → review-
Created attachment 652208 [details] [diff] [review]
Patch v2

A for-reals patch now.
Attachment #652206 - Attachment is obsolete: true
Attachment #652208 - Flags: review?(bugmail)
Just a note, I talked to bbondy in #windev about the inconsistency, and he acknowledged it (nsLocalFileWin.cpp stashes the lastModifiedTime and fileSize at instantiation), and said that using clone() is a fine workaround.
Comment on attachment 652208 [details] [diff] [review]
Patch v2

r=asuth with the understanding that the best-suited reviewer is on vacation.

Karma points are at risk for making main thread I/O more I/O'y (albeit in the name of correctness)!
Attachment #652208 - Flags: review?(bugmail) → review+
As an additional data point, I remember getting a patch like this from David on a bug previously, although I can't find the instance of it at the moment.
Attachment #652208 - Flags: approval-comm-beta?
Attachment #652208 - Flags: approval-comm-aurora?
Last Resolved: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 17.0
Comment on attachment 652208 [details] [diff] [review]
Patch v2

Hm. So I could have sworn this patch worked...but today's Daily (which contains the patch) is still not indexing my IM's as they come in.

What's more, these messages are not being indexed even after a restart.

Starting investigation...
Attachment #652208 - Flags: approval-comm-beta?
Attachment #652208 - Flags: approval-comm-aurora?
Backed out patch on comm-central for now until I can figure out what's going on:
Resolution: FIXED → ---
The problem is sporadic, and seems to (again) be related to lastModifiedTime.

It *appears* as if NTFS doesn't update lastModifiedTime immediately on file-write...I think it lazily writes it after some period, and *sometimes* that period falls outside of the point when our indexer kicks off, meaning that the doesn't look like it was modified.

I'm not too familiar with the inner workings of NTFS to know if what I'm saying is true, but it's what *appears* to be happening.

The (kind of) good news is that this behaviour is sporadic, and the messages *should* get re-indexed when the conversation is modified and lastModifiedTime is updated, or on restart.

I'm still convinced that we're doing the right thing with this patch, so I'm going to put it back and a? again for aurora / beta.

The whole non-indexing of messages thing I was experiencing is (I believe) a separate bug. I'll file that in a second.
Re-landed on comm-central as
Last Resolved: 5 years ago5 years ago
Resolution: --- → FIXED
Attachment #652208 - Flags: approval-comm-beta?
Attachment #652208 - Flags: approval-comm-aurora?
Attachment #652208 - Flags: approval-comm-beta?
Attachment #652208 - Flags: approval-comm-beta+
Attachment #652208 - Flags: approval-comm-aurora?
Attachment #652208 - Flags: approval-comm-aurora+
status-thunderbird15: --- → fixed
status-thunderbird16: --- → fixed
tracking-thunderbird15: ? → ---
tracking-thunderbird16: ? → ---
You need to log in before you can comment on or make changes to this bug.