Adium

Opened 5 years ago

Closed 5 years ago

#15699 closed defect (fixed)

Adium log viewer returns 0 chats for any query

Reported by: arranger Owned by:
Milestone: Adium 1.5.3 Component: Adium Core
Version: 1.5b7 Severity: regression
Keywords: chat log viewer Cc:
Patch Status:

Description (last modified by Robby)

Summary

When searching for anything in the Adium chat log viewer it returns always 0 chats.

Steps to reproduce

  1. Open the chat log viewer
  2. Select a contact or all contacts
  3. Type a word (or even just a letter) in the topright search filed

Expected results

Some chat log containing the searched words.

Actual results

No chats returned as result of the search.

Notes

Trying to reindex the chat logs (File -> import -> reindex adium logs) does not help (some user suggested to do so).
This is the debug log I get after I open the Adium chat log viewer:

20:05:55: void __33-[AILoggerPlugin logContentIndex]_block_invoke_0(): AILoggerPlugin warning: SKIndexCreateWithURL() returned NULL
20:05:55: Displaying (null)
20:05:55: void __33-[AILoggerPlugin logContentIndex]_block_invoke_0(): AILoggerPlugin warning: SKIndexCreateWithURL() returned NULL
20:05:55: -[AILoggerPlugin _cleanDirtyLogs]: *** Warning: Could not open searchIndex in -[<AILoggerPlugin: 0x1026c9a70> _cleanDirtyLogs]. That shouldn't happen!
20:05:55: Starting a search for (null)
20:05:55: void __33-[AILoggerPlugin logContentIndex]_block_invoke_0(): AILoggerPlugin warning: SKIndexCreateWithURL() returned NULL
20:05:55: filterLogsWithSearch (search ID 1): {
    ID = 1;
    Mode = 3;
}
20:05:55: refreshResultsSearchIsComplete: 1 (count is 1288)
20:05:55: filterLogsWithSearch (search ID 1): finished
20:05:55: Displaying (
    "<AIChatLog: 0x10c2bdf00>"
)
20:05:55: Displaying (
    "<AIChatLog: 0x10c2bdf00>"
)

and this is what I get after I try to reindex the logs:

    20:07:30: Starting a search for (null)
    20:07:30: void __33-[AILoggerPlugin logContentIndex]_block_invoke_0(): AILoggerPlugin warning: SKIndexCreateWithURL() returned NULL
    20:07:30: filterLogsWithSearch (search ID 2): {
        ID = 2;
        Mode = 3;
    }
    20:07:30: void __31-[AILoggerPlugin _dirtyAllLogs]_block_invoke_0(): Finished dirtying all logs
    20:07:30: void __34-[AILoggerPlugin _saveDirtyLogSet]_block_invoke_0(): Saving 5240 dirty logs
    20:07:30: void __33-[AILoggerPlugin logContentIndex]_block_invoke_0(): AILoggerPlugin warning: SKIndexCreateWithURL() returned NULL
    20:07:30: -[AILoggerPlugin _cleanDirtyLogs]: *** Warning: Could not open searchIndex in -[<AILoggerPlugin: 0x1026c9a70> _cleanDirtyLogs]. That shouldn't happen!
    20:07:30: refreshResultsSearchIsComplete: 1 (count is 5240)
    20:07:30: filterLogsWithSearch (search ID 2): finished
    20:07:30: Displaying (
        "<AIChatLog: 0x10c2bdf00>"
    )

Additional Notes

Using Adium 1.5bX under Mac OS X Lion 10.7.2

Attachments (3)

LogSearchIndex.log (92.1 KB) - added by Skyrazer 5 years ago.
Messages while reproducing the error.
SelectingTranscriptsSample_1.txt (56.2 KB) - added by Skyrazer 5 years ago.
SelectingTranscriptsSample_2.txt (65.5 KB) - added by Skyrazer 5 years ago.

Download all attachments as: .zip

Change History (56)

comment:1 Changed 5 years ago by Robby

  • Milestone set to Adium 1.5
  • Severity changed from normal to regression

comment:2 Changed 5 years ago by Robby

"arranger" told us more about this on IRC: http://www.adium.im/~cappuccino/%23adium/%23adium.2011-12-13.log.

comment:4 Changed 5 years ago by Peter Hosey <hg@…>

(In 1a3047f3c8df) Log the arguments to SKIndexCreateWithURL, so we can be sure it isn't our fault (or find out how it is). Refs #15699.

comment:5 Changed 5 years ago by Robby

Hey arranger,

Could you please try the latest nightly which should include the added debug information and post a debug log for the issue?

Last edited 5 years ago by Robby (previous) (diff)

comment:6 follow-up: Changed 5 years ago by arranger

comment:7 in reply to: ↑ 6 Changed 5 years ago by boredzo

Replying to arranger:

Here is the log, hope it helps … http://pastebin.com/913TXSAW

That shows the index being successfully created. Are you now able to search for logs?

comment:8 Changed 5 years ago by arranger

It shows just the last conversation (the one I had after using the nightly build). It seems like he created the index only on that chat. Does it mean the problem is solved with the nightly build?

comment:9 Changed 5 years ago by boredzo

Let's find out. What happens if you go back to the Reindex command?

comment:10 follow-up: Changed 5 years ago by arranger

shall I now use the nightly build or the currently beta?

comment:11 in reply to: ↑ 10 Changed 5 years ago by boredzo

Replying to arranger:

shall I now use the nightly build or the currently beta?

The nightly, since the beta (being the same one as before) doesn't log anything useful if it fails.

comment:12 follow-up: Changed 5 years ago by arranger

Reindexing now works, the status bar shows the progress of indexing now and when terminated I can search and it outputs some results. Here is the debug log http://pastebin.com/iLb07VRM

comment:13 in reply to: ↑ 12 Changed 5 years ago by boredzo

Replying to arranger:

Reindexing now works, the status bar shows the progress of indexing now and when terminated I can search and it outputs some results.

Sounds like the problem is cleared, then.

comment:14 follow-up: Changed 5 years ago by arranger

well, yes. Has something been done to the reindexing code in this nightly build?

comment:15 in reply to: ↑ 14 Changed 5 years ago by boredzo

Replying to arranger:

Has something been done to the reindexing code in this nightly build?

Just my logging change. Nothing that would have fixed a bug.

So if there is a bug in Adium, it remains unfixed and undiscovered. Fortunately, if it happens again, there is now a log message that will reveal the input values with which failed.

comment:16 Changed 5 years ago by sphynx

I meant to mention this ticket in these commits, but used the wrong number.

(In c0dcb2b73496) Don't crash when the log index failed to initialize when trying to delete a log, just bail.

Fixes #15771, refs #13586


(In f272f5b32043) It was possible that two threads were trying to open the same index at the same time, so this check has to be in the dispatch_sync block.

Also, add some more logging when an index is actually closed.

Refs #13586

comment:17 Changed 5 years ago by sphynx

If anyone still sees this with rc1, or a nightly from somewhere in the past week, please comment. Otherwise, I think the second of my commits in the previous post fixed it.

comment:18 Changed 5 years ago by paulwilde

  • Status changed from new to pending

comment:19 Changed 5 years ago by trac-robot

  • Status changed from pending to closed

This ticket was closed automatically by the system. It was previously set to a Pending status and hasn't been updated within 3 days.

comment:20 Changed 5 years ago by robotive

  • Status changed from closed to new

comment:21 Changed 5 years ago by robotive

  • Status changed from new to pending

comment:22 Changed 5 years ago by trac-robot

  • Status changed from pending to closed

This ticket was closed automatically by the system. It was previously set to a Pending status and hasn't been updated within 14 days.

comment:23 Changed 5 years ago by Robby

  • Status changed from closed to new

comment:24 follow-up: Changed 5 years ago by Robby

  • Status changed from new to pending

comment:25 in reply to: ↑ 24 ; follow-up: Changed 5 years ago by Skyrazer

The problem occurred to me yesterday with rc3. After I found this ticket I reindexed the log files manually using the menu and it worked fine:

14:53:42: updateSearch calling startSearching
14:53:42: Starting a search for düse bestellen
14:53:42: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 26: {
    ID = 26;
    Mode = 3;
    String = "d\U00fcse bestellen";
}
14:53:42: refreshResultsSearchIsComplete: 1 (count is 4)
14:53:42: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 26): finished
14:53:42: Displaying (
    "<AIChatLog: 0x19578c10>",
    "<AIChatLog: 0x195add00>",
    "<AIChatLog: 0x195adce0>",
    "<AIChatLog: 0x1959e4a0>"
)
  1. I then searched for something different, which also worked. I then deleted the query string an nothing happened anymore:
14:59:05: updateSearch calling startSearching
14:59:05: Starting a search for 
14:59:05: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 39: {
    ID = 39;
    Mode = 3;
    String = "";
}
14:59:06: refreshResultsSearchIsComplete: 0 (count is 0)
14:59:06: Displaying (null)
14:59:07: refreshResultsSearchIsComplete: 0 (count is 0)
14:59:07: Displaying (null)
14:59:08: refreshResultsSearchIsComplete: 0 (count is 0)
14:59:08: Displaying (null)
14:59:09: refreshResultsSearchIsComplete: 0 (count is 0)
14:59:09: Displaying (null)
14:59:10: refreshResultsSearchIsComplete: 0 (count is 0)
14:59:10: Displaying (null)
14:59:11: refreshResultsSearchIsComplete: 0 (count is 0)
14:59:11: Displaying (null)
14:59:12: refreshResultsSearchIsComplete: 0 (count is 0)
14:59:12: Displaying (null)
...
  1. Even selecting a different user didn't stop the loop. I had to close the log window:
    15:01:43: -[AILoggerPlugin _flushIndex:]: **** Flushing index 0x160cf670
    15:01:44: -[AILoggerPlugin _flushIndex:]: **** Finished flushing index 0x160cf670, and released it
    15:01:44: __32-[AILoggerPlugin _closeLogIndex]_block_invoke_0: **** Finished closing index 0x160cf670
    
  1. When reopening the log viewer it says:
    15:02:37: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: Opened index 0 from file://localhost/Users/joey/Library/Caches/Adium/Default/Logs.index
    15:02:37: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: *** Warning: The Chat Transcript searching index at /Users/joey/Library/Caches/Adium/Default/Logs.index was corrupt. Removing it and starting fresh; transcripts will be re-indexed automatically.
    15:02:37: Displaying (null)
    15:02:37: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: AILoggerPlugin warning: SKIndexCreateWithURL(file://localhost/Users/joey/Library/Caches/Adium/Default/Logs.index, Content, 1, {
        kSKMaximumTerms = 0;
        kSKMinTermLength = 2;
        kSKProximityIndexing = 1;
    }) returned NULL
    15:02:37: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: AILoggerPlugin warning: SKIndexCreateWithURL(file://localhost/Users/joey/Library/Caches/Adium/Default/Logs.index, Content, 1, {
        kSKMaximumTerms = 0;
        kSKMinTermLength = 2;
        kSKProximityIndexing = 1;
    }) returned NULL
    15:02:37: -[AILoggerPlugin _cleanDirtyLogs]: *** Warning: Could not open searchIndex in -[<AILoggerPlugin: 0x264cff0> _cleanDirtyLogs]. That shouldn't happen!
    [...]
    15:02:37: Starting a search for (null)
    15:02:37: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 1: {
        ID = 1;
        Mode = 3;
    }
    15:02:37: refreshResultsSearchIsComplete: 1 (count is 1666)
    15:02:37: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 1): finished
    15:02:37: Displaying (
        "<AIChatLog: 0x1eb12b40>"
    )
    15:02:37: Displaying (
        "<AIChatLog: 0x1eb12b40>"
    )
    15:03:19: updateSearch calling startSearching
    15:03:19: Starting a search for düse
    15:03:19: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 2: {
        ID = 2;
        Mode = 3;
        String = "d\U00fcse";
    }
    15:03:19: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: AILoggerPlugin warning: SKIndexCreateWithURL(file://localhost/Users/joey/Library/Caches/Adium/Default/Logs.index, Content, 1, {
        kSKMaximumTerms = 0;
        kSKMinTermLength = 2;
        kSKProximityIndexing = 1;
    }) returned NULL
    15:03:19: refreshResultsSearchIsComplete: 1 (count is 0)
    15:03:19: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 2): finished
    15:03:19: Displaying (null)
    15:03:19: Displaying (
    )
    15:03:20: updateSearch calling startSearching
    15:03:20: Starting a search for düse 
    15:03:20: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 3: {
        ID = 3;
        Mode = 3;
        String = "d\U00fcse ";
    }
    15:03:20: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: AILoggerPlugin warning: SKIndexCreateWithURL(file://localhost/Users/joey/Library/Caches/Adium/Default/Logs.index, Content, 1, {
        kSKMaximumTerms = 0;
        kSKMinTermLength = 2;
        kSKProximityIndexing = 1;
    }) returned NULL
    15:03:20: refreshResultsSearchIsComplete: 1 (count is 0)
    15:03:20: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 3): finished
    15:03:20: Displaying (null)
    15:03:22: updateSearch calling startSearching
    15:03:22: Starting a search for düse bestellen
    15:03:22: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 4: {
        ID = 4;
        Mode = 3;
        String = "d\U00fcse bestellen";
    }
    15:03:22: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: AILoggerPlugin warning: SKIndexCreateWithURL(file://localhost/Users/joey/Library/Caches/Adium/Default/Logs.index, Content, 1, {
        kSKMaximumTerms = 0;
        kSKMinTermLength = 2;
        kSKProximityIndexing = 1;
    }) returned NULL
    15:03:22: refreshResultsSearchIsComplete: 1 (count is 0)
    15:03:22: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 4): finished
    15:03:22: Displaying (null)
    
  1. As you see, search is broken and I'd have to reindex the log files to make it work again. But this didn't work:
    15:10:19: -[AILoggerPlugin _cleanDirtyLogs]: *** Warning: Could not open searchIndex in -[<AILoggerPlugin: 0x264cff0> _cleanDirtyLogs]. That shouldn't happen!
    15:10:33: __31-[AILoggerPlugin _dirtyAllLogs]_block_invoke_0721: Finished dirtying all logs
    15:10:33: __34-[AILoggerPlugin _saveDirtyLogSet]_block_invoke_0: Saving 5392 dirty logs
    15:10:33: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: AILoggerPlugin warning: SKIndexCreateWithURL(file://localhost/Users/joey/Library/Caches/Adium/Default/Logs.index, Content, 1, {
        kSKMaximumTerms = 0;
        kSKMinTermLength = 2;
        kSKProximityIndexing = 1;
    }) returned NULL
    15:10:33: -[AILoggerPlugin _cleanDirtyLogs]: *** Warning: Could not open searchIndex in -[<AILoggerPlugin: 0x264cff0> _cleanDirtyLogs]. That shouldn't happen!
    
  1. I had to restart Adium
    15:12:32: __34-[AILoggerPlugin _loadDirtyLogSet]_block_invoke_0: Loaded dirty log set with 5393 logs
    
  1. Open the log viewer again
    15:14:19: __33-[AILoggerPlugin logContentIndex]_block_invoke_0: Created a new log index 1ccdaae0 at file://localhost/Users/joey/Library/Caches/Adium/Default/Logs.index with textAnalysisProperties {
        kSKMaximumTerms = 0;
        kSKMinTermLength = 2;
        kSKProximityIndexing = 1;
    }. Will reindex all logs.
    15:14:19: -[AILoggerPlugin _flushIndex:]: **** Flushing index 0x1ccdaae0
    15:14:19: -[AILoggerPlugin _flushIndex:]: **** Finished flushing index 0x1ccdaae0, and released it
    15:14:20: Starting a search for (null)
    15:14:20: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 1: {
        ID = 1;
        Mode = 3;
    }
    15:14:20: refreshResultsSearchIsComplete: 1 (count is 1666)
    15:14:20: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 1): finished
    15:14:20: Displaying (
        "<AIChatLog: 0x1b9bd450>"
    )
    15:14:20: Displaying (
        "<AIChatLog: 0x1b9bd450>"
    )
    
  1. and reindex the log files
    15:16:07: refreshResultsSearchIsComplete: 1 (count is 5392)
    15:16:07: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 5): finished
    15:16:07: __31-[AILoggerPlugin _dirtyAllLogs]_block_invoke_0721: Finished dirtying all logs
    15:16:07: __34-[AILoggerPlugin _saveDirtyLogSet]_block_invoke_0: Saving 5393 dirty logs
    15:16:07: -[AILoggerPlugin _cleanDirtyLogs]: Cleaning 5393 dirty logs
    15:16:49: __34-[AILoggerPlugin _saveDirtyLogSet]_block_invoke_0: Saving 3379 dirty logs
    15:17:39: __34-[AILoggerPlugin _saveDirtyLogSet]_block_invoke_0: Saving 1377 dirty logs
    15:18:11: __34-[AILoggerPlugin _saveDirtyLogSet]_block_invoke_0: Saving 0 dirty logs
    15:18:11: -[AILoggerPlugin _flushIndex:]: **** Flushing index 0x1ccdaae0
    15:18:19: -[AILoggerPlugin _flushIndex:]: **** Finished flushing index 0x1ccdaae0, and released it
    15:18:19: __block_global_9: After cleaning dirty logs, the search index has a max ID of 5688 and a count of 5668
    

First it seemed to me that step 1 caused the error, but after the restart of Adium I wasn't able to reproduce it. Search works fine since then. So I wasn't able to locate the problem. But maybe you can get useful information of these logs. ;-)

I managed to reproduce the error mentioned in step 1:

  1. In the log viewer select a user with really many logs (> 1600 in my case)
  2. Select all of them (command-a)
  3. While it shows "Loading ..." enter a query string into the search field

I had to try it several times using different strings, then this exception was thrown:

16:18:34: updateSearch calling startSearching
16:18:34: Starting a search for die k
16:18:34: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 31: {
    ID = 31;
    Mode = 3;
    String = "die k";
}
16:18:34: -[ESDebugController exceptionHandler:shouldLogException:mask:]: Exception raised: Invalid parameter not satisfying: [sourceArray count] >= [self numberOfRows]
16:18:34: 0   Adium                               0x00527f1e AILogBacktrace_impl + 40
1   Adium                               0x00068df6 -[ESDebugController exceptionHandler:shouldLogException:mask:] + 67
2   ExceptionHandling                   0x90075ebb -[NSExceptionHandler _handleException:mask:] + 331
3   ExceptionHandling                   0x90075d52 NSExceptionHandlerExceptionRaiser + 228
4   libobjc.A.dylib                     0x999b15a9 objc_exception_throw + 56
5   CoreFoundation                      0x967fa3f8 +[NSException raise:format:arguments:] + 136
6   Foundation                          0x976356e7 -[NSAssertionHandler handleFailureInMethod:object:file:lineNumber:description:] + 116
7   AIUtilities                         0x003a8310 -[NSTableView(AITableViewAdditions) selectedItemsFromArray:] + 184
8   Adium                               0x000c8e25 -[AILogViewerWindowController tableViewSelectionDidChangeDelayed] + 83
9   Foundation                          0x97582369 __NSFireDelayedPerform + 537
10  CoreFoundation                      0x96764a3b __CFRunLoopRun + 8059
11  CoreFoundation                      0x967623c4 CFRunLoopRunSpecific + 452
12  CoreFoundation                      0x967621f1 CFRunLoopRunInMode + 97
13  HIToolbox                           0x93460e04 RunCurrentEventLoopInMode + 392
14  HIToolbox                           0x93460bb9 ReceiveNextEventCommon + 354
15  HIToolbox                           0x93460a3e BlockUntilNextEventMatchingListInMode + 81
16  AppKit                              0x90f59595 _DPSNextEvent + 847
17  AppKit                              0x90f58dd6 -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] + 156
18  AppKit                              0x90f1b1f3 -[NSApplication run] + 821
19  AppKit                              0x90f13289 NSApplicationMain + 574
20  Adium                               0x00002d35 start + 53
16:18:34: updateSearch calling startSearching
16:18:34: Starting a search for die klei
16:18:34: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 32: {
    ID = 32;
    Mode = 3;
    String = "die klei";
}
16:18:35: updateSearch calling startSearching
16:18:35: Starting a search for die kleine
16:18:35: -[AILogViewerWindowController filterLogsWithSearch:]: Search ID 33: {
    ID = 33;
    Mode = 3;
    String = "die kleine";
}
16:18:36: refreshResultsSearchIsComplete: 0 (count is 0)
16:18:36: Displaying (null)
16:18:36: Displaying (
)
16:18:37: refreshResultsSearchIsComplete: 0 (count is 0)
16:18:37: Displaying (null)
16:18:38: refreshResultsSearchIsComplete: 0 (count is 0)
16:18:38: Displaying (null)
[... looping on and on ...]

After this you can proceed with step 2. ;-)

Last edited 5 years ago by Skyrazer (previous) (diff)

comment:26 Changed 5 years ago by Robby

  • Status changed from pending to new

Wow, that looks useful. :)

comment:27 in reply to: ↑ 25 ; follow-up: Changed 5 years ago by sphynx

Skyrazer: I've been trying to follow your steps, but I'm not seeing the same problem as you are.

Replying to Skyrazer:

[... looping on and on ...]

Did you leave this for a while? Was the window still showing "Saving search index"? I've heard from some people this part can take 30 seconds, in that time no search results will show up yet.


Maybe this is now fixed in fceff51f0ad7, this should ensure the search index is flushed before searching.

Changed 5 years ago by Skyrazer

Messages while reproducing the error.

comment:28 in reply to: ↑ 27 ; follow-up: Changed 5 years ago by Skyrazer

Replying to sphynx:

Did you leave this for a while? Was the window still showing "Saving search index"? I've heard from some people this part can take 30 seconds, in that time no search results will show up yet.

I did. I attached a log file with all the entries that show up while reproducing the error. From 09:50:39 on, search is definitely broken. The UI behaves weird also: The "Loading ..." message inside the text window starts and keeps blinking and doesn't disappear.

Maybe this is now fixed in fceff51f0ad7, this should ensure the search index is flushed before searching.

Is this revision included in the current nightly? Please tell me if so I could retest this issue.

comment:29 in reply to: ↑ 28 Changed 5 years ago by robotive

Replying to Skyrazer:

Maybe this is now fixed in fceff51f0ad7, this should ensure the search index is flushed before searching.

Is this revision included in the current nightly? Please tell me if so I could retest this issue.

No, it will be in the next nightly, due in ~ 1 hour.

comment:30 follow-up: Changed 5 years ago by robotive

Skyrazer,

the new nightly is ready for you to test :)

comment:31 in reply to: ↑ 30 Changed 5 years ago by Skyrazer

Replying to robotive:

the new nightly is ready for you to test :)

Thank you! :)

But I have to report: The problem still occurs:

16:14:42: -[AILogViewerWindowController _logContentFilter:searchID:onSearchIndex:]:1584: (on com.apple.root.default-overcommit-priority) Calling flush
16:14:42: -[AILogViewerWindowController _logContentFilter:searchID:onSearchIndex:]:1586: (on com.apple.root.default-overcommit-priority) Done flushing. Now we can search.
16:14:42: -[ESDebugController exceptionHandler:shouldLogException:mask:]:76: Exception raised: Invalid parameter not satisfying: [sourceArray count] >= [self numberOfRows]
16:14:42: 0   Adium                               0x00531d57 AILogBacktrace_impl + 40
1   Adium                               0x00069abc -[ESDebugController exceptionHandler:shouldLogException:mask:] + 69
2   ExceptionHandling                   0x96c9cebb -[NSExceptionHandler _handleException:mask:] + 331
3   ExceptionHandling                   0x96c9cd52 NSExceptionHandlerExceptionRaiser + 228
4   libobjc.A.dylib                     0x99a555a9 objc_exception_throw + 56
5   CoreFoundation                      0x99e633f8 +[NSException raise:format:arguments:] + 136
6   Foundation                          0x92db36e7 -[NSAssertionHandler handleFailureInMethod:object:file:lineNumber:description:] + 116
7   AIUtilities                         0x003ae130 -[NSTableView(AITableViewAdditions) selectedItemsFromArray:] + 184
8   Adium                               0x000c9b03 -[AILogViewerWindowController tableViewSelectionDidChangeDelayed] + 83
9   Foundation                          0x92d00369 __NSFireDelayedPerform + 537
10  CoreFoundation                      0x99dcda3b __CFRunLoopRun + 8059
11  CoreFoundation                      0x99dcb3c4 CFRunLoopRunSpecific + 452
12  CoreFoundation                      0x99dcb1f1 CFRunLoopRunInMode + 97
13  HIToolbox                           0x95a78e04 RunCurrentEventLoopInMode + 392
14  HIToolbox                           0x95a78bb9 ReceiveNextEventCommon + 354
15  HIToolbox                           0x95a78a3e BlockUntilNextEventMatchingListInMode + 81
16  AppKit                              0x98127595 _DPSNextEvent + 847
17  AppKit                              0x98126dd6 -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] + 156
18  AppKit                              0x980e91f3 -[NSApplication run] + 821
19  AppKit                              0x980e1289 NSApplicationMain + 574
20  Adium                               0x00003875 start + 53
16:14:42: updateSearch calling startSearching
16:14:42: Starting a search for die klein
16:14:42: -[AILogViewerWindowController filterLogsWithSearch:]:1724: (on com.apple.root.default-overcommit-priority) Search ID 25: {
    ID = 25;
    Mode = 3;
    String = "die klein";
}
16:14:42: -[AILogViewerWindowController _logContentFilter:searchID:onSearchIndex:]:1584: (on com.apple.root.default-overcommit-priority) Calling flush
16:14:42: -[AILogViewerWindowController _logContentFilter:searchID:onSearchIndex:]:1586: (on com.apple.root.default-overcommit-priority) Done flushing. Now we can search.
16:14:43: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:43: Displaying (
)
16:14:44: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:45: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:46: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:47: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:48: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:49: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:50: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:51: refreshResultsSearchIsComplete: 0 (count is 0)
16:14:52: refreshResultsSearchIsComplete: 0 (count is 0)

The UI is fixed: "Loading ..." is not blinking anymore. ;-)

I've also tried if this has something to do with account types. But I can make this happen with logs of a jabber account as well as with my twitter timeline logs.

comment:32 follow-up: Changed 5 years ago by Robby

Do you happen to have a huge amount of transcripts?

comment:33 in reply to: ↑ 32 Changed 5 years ago by Skyrazer

Replying to Robby:

Do you happen to have a huge amount of transcripts?

Do you mean the chat logs? I probably do have. More than 5400 altogether, more than 1600 for some single users.

comment:34 Changed 5 years ago by robotive

  • Milestone changed from Adium 1.5 to Adium 1.5.1

comment:35 Changed 5 years ago by evands

Did this get fixed in later nightlies?

comment:36 Changed 5 years ago by Robby

  • Description modified (diff)
  • Milestone Adium 1.5.1 deleted
  • Resolution set to fixed
  • Status changed from new to closed

Good question

Skyrazer and others, please let us know if you are still seeing this issue.

comment:37 follow-up: Changed 5 years ago by Skyrazer

It still looks like this is totally broken:

  1. Using search I can break the index
  2. Trying to rebuild the index it hangs at 5914 or 5910 of 5938 logs
  3. Trying to cancel (close window) and rebuild index again: nothing happens
  4. Quitting adium, trying to rebuild index (works), then stops at 2.

The logs do not show anything helpful in the moment, I think.

comment:38 in reply to: ↑ 37 Changed 5 years ago by jesse@…

I am seeing the same issue as comment:37.

  1. Search for something in Chat Transcript Viewer that I know has results, but get no results
  2. Indexer is stuck at the bottom saying "Indexing 1251 of 1267 transcripts..."
  3. File -> Import -> Reindex Adium Logs does nothing

Seems there is something in my logs stalling the indexer.

I was actually able to narrow down one of the logs that is messing up the indexer. It's only 159 lines long, but somehow the xml got all corrupted from lines 134-140:

134 <status type="disconnected" sender="myname@support.mycompany.com" time="2011-08-29T09:06:56-04:00" alias="Myfirstname Mylastname"><div>You have disconnected</div></status< 
135 <status type="connected" time="2011-08-29T09:08:39-04:00"><div>You have connected</div></status> 
136 <message sender="support@conference.support.mycompany.com/Joe Smith" time="2011-08-26T11:57:31-04:00" alias="Joe Smith"><div><span style="font-family: Helvetica; font-size: 18pt;">but</span></div></message> 
137 <message sender="support@conference.support.mycompany.com/Joe Smith" time="2011-08-26T11:58:08-04:00" alias=" 
138 <event type="windowOpened" sender="myname@support.mycompany.com" time="2011-08-29T09:53:45-04:00"></event> 
139 <event type="windowOpened" sender="myname@support.mycompany.com" time="2011-08-29T09:54:57-04:00"></event> 
140 <event type="windowOpened" sender="myname@support.mycompany.com" time="2011-08-29T15:29:18-04:00"></event></?xml>t-family: Helvetica; font-size: 12pt;">bb, you&apos;ve got to show me how you got the umlaut in Dunkel in there :)</span></div></message>

I removed these lines and the xml was then valid and the indexer able to proceed

comment:39 Changed 5 years ago by Skyrazer

comment:38 looks very reasonable to me: I am mainly using XMPP as well, so the problem with indexing might result out of broken xml, too. I don't know if this is the cause breaking the index though.

comment:40 follow-up: Changed 5 years ago by Robby

  • Resolution fixed deleted
  • Status changed from closed to new

Everyone, please try this build: http://nightly.adium.im/adium-adium-1.5.2/Adium_1.5.2b1r4873.dmg and let us know how it works in relation to the issue described here.

comment:41 in reply to: ↑ 40 Changed 5 years ago by goatbert

Replying to Robby:

Everyone, please try this build: http://nightly.adium.im/adium-adium-1.5.2/Adium_1.5.2b1r4873.dmg and let us know how it works in relation to the issue described here.

http://cdn.memegenerator.net/instances/400x/22346212.jpg

09:43:26: __34-[AILoggerPlugin _saveDirtyLogSet]_block_invoke_0:1630: (on im.adium.AILoggerPlugin.dirtyLogSetMutationQueue) Saving 1478 dirty logs
09:43:26: __34-[AILoggerPlugin _saveDirtyLogSet]_block_invoke_0:1630: (on im.adium.AILoggerPlugin.dirtyLogSetMutationQueue) Saving 0 dirty logs
09:43:26: -[AILoggerPlugin _flushIndex:]:1679: (on im.adium.AILoggerPlugin.searchIndexFlushingQueue) **** Flushing index 0x10dc09290
09:43:47: -[AILoggerPlugin _flushIndex:]:1684: (on im.adium.AILoggerPlugin.searchIndexFlushingQueue) **** Finished flushing index 0x10dc09290
09:43:47: __block_global_9:1585: (on im.adium.AILoggerPlugin.searchIndexFlushingQueue) After cleaning dirty logs, the search index has a max ID of 98387 and a count of 24786

Sorry for the meme but it was perfect. Thanks for the fix!

comment:42 Changed 5 years ago by Robby

Haha, I (and I know others did) enjoyed that. ;)


arranger, Skyrazer, jesse@jessejoe.com,

What about you folks? Are you able to confirm this issue is fixed with the build linked above? :)

Last edited 5 years ago by Robby (previous) (diff)

comment:43 Changed 5 years ago by therealcmj

Confirmed that this fixed the issue for me as well.

comment:44 follow-ups: Changed 5 years ago by Skyrazer

Ok, the good news:
The search and index issue seems to be fixed: Index building and every search request performed well! Great work, thanks a lot!

The bad news (sorry for being the bad guy in this movie):
Selecting all transcripts of a user (3151 in this case) will crash Adium: It shows "Loading ...", then CPU usage goes very high, then Adium does not react anymore and I have to force quit it. The log shows nothing, but:

08:51:31: Displaying (
    "<AIChatLog: 0x1a7f0b60>",
    "<AIChatLog: 0x1a7f0a70>",
...

Maybe some kind of buffer overflow?

Edit: I tested this using 1.5.2b1

Last edited 5 years ago by Skyrazer (previous) (diff)

comment:45 in reply to: ↑ 44 Changed 5 years ago by mathuaerknedam

Replying to Skyrazer:

CPU usage goes very high, then Adium does not react anymore and I have to force quit it.

Please attach a sample.

Changed 5 years ago by Skyrazer

Changed 5 years ago by Skyrazer

comment:46 Changed 5 years ago by Skyrazer

There they are!

I just recognized that Adium is not crashing but just hanging. After a few minutes it will finish the selection and show the selected transcripts. Meanwhile it will have lost its connections and reconnect when the selection is done.

comment:47 Changed 5 years ago by Robby

I believe a new bug report would be in order as this last report of a hang has very little to do with the originally reported issue.

Last edited 5 years ago by Robby (previous) (diff)

comment:48 in reply to: ↑ 44 ; follow-up: Changed 5 years ago by sphynx

Replying to Skyrazer:

Ok, the good news:
The search and index issue seems to be fixed: Index building and every search request performed well! Great work, thanks a lot!

The bad news (sorry for being the bad guy in this movie):
Selecting all transcripts of a user (3151 in this case) will crash Adium: It shows "Loading ...", then CPU usage goes very high, then Adium does not react anymore and I have to force quit it. The log shows nothing, but:

08:51:31: Displaying (
    "<AIChatLog: 0x1a7f0b60>",
    "<AIChatLog: 0x1a7f0a70>",
...

Maybe some kind of buffer overflow?

Edit: I tested this using 1.5.2b1

That's not related to this ticket, and not very surprising. I don't know how long these transcripts are, but 3151 is a pretty high number if they have hundreds of messages. While most of the parsing and formatting is done on a separate thread, at some point Adium has to draw it and it can do nothing else for that time.

There are some ways it could be improved if the delay is that bad, but then please open a new ticket for it.

comment:49 in reply to: ↑ 48 Changed 5 years ago by Skyrazer

Replying to sphynx:

That's not related to this ticket, and not very surprising. I don't know how long these transcripts are, but 3151 is a pretty high number if they have hundreds of messages. While most of the parsing and formatting is done on a separate thread, at some point Adium has to draw it and it can do nothing else for that time.

There are some ways it could be improved if the delay is that bad, but then please open a new ticket for it.

Yep, it's a lot. I'll create a new ticket for this. The selection problem also breaks the search index again. Is this related to this ticket?

17:36:21: -[AILoggerPlugin _cleanDirtyLogs]:1442: (on com.apple.root.low-priority) *** Warning: Could not open searchIndex in -[<AILoggerPlugin: 0x21b66d0> _cleanDirtyLogs]. That shouldn't happen!

EDIT: Tried again. The index still seems to be ok, now. Don't know whatever broke it before. I'll create a new ticket and this one is fixed then. :)

Last edited 5 years ago by Skyrazer (previous) (diff)

comment:50 Changed 5 years ago by Robby

We'd appreciate a new ticket, thanks!

comment:51 Changed 5 years ago by Robby

  • Milestone set to Adium 1.5.3
  • Status changed from new to pending

Please try the 1.5.3 beta. For me, indexing and searching are finally working reliably.

Last edited 5 years ago by Robby (previous) (diff)

comment:52 Changed 5 years ago by Skyrazer

Yep. Works nicely.

comment:53 Changed 5 years ago by Robby

  • Resolution set to fixed
  • Status changed from pending to closed

Yay!

If anybody finds otherwise, please comment and we'll revisit the issue.

Note: See TracTickets for help on using tickets.