RuntimeError from thread: poll after loading inbox.

[GuillaumeSeren]

Hello, I got a crash while passive polling: --- RuntimeError from thread: poll after loading inbox

/var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:615:in find_docid' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:620:infind_doc' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:181:in message_joining_killed?' (eval):1:inmessage_joining_killed?' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:217:in block in poll_from' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/maildir.rb:161:inblock in poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/maildir.rb:160:in each' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/maildir.rb:160:ineach_with_index' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/maildir.rb:160:in poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:201:inpoll_from' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:146:in block (2 levels) in do_poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:136:ineach' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:136:in block in do_poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:135:insynchronize' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:135:in do_poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/util.rb:658:inmethod_missing' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/modes/poll_mode.rb:15:in poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:58:inpoll_with_sources' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:94:in poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/util.rb:658:inmethod_missing' /var/lib/gems/2.1.0/gems/sup-0.20.0/bin/sup:222:in block (2 levels) in <module:Redwood>' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup.rb:88:inblock in reporting_thread' --- RuntimeError from thread: periodic poll

/var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:615:in find_docid' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:620:infind_doc' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:803:in block in index_message_threading' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:803:inmap' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:803:in index_message_threading' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:717:insync_message' (eval):1:in sync_message' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:215:inblock in poll_from' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/maildir.rb:161:in block in poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/maildir.rb:160:ineach' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/maildir.rb:160:in each_with_index' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/maildir.rb:160:inpoll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:201:in poll_from' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:146:inblock (2 levels) in do_poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:136:in each' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:136:inblock in do_poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:135:in synchronize' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:135:indo_poll' (eval):1:in do_poll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/modes/poll_mode.rb:15:inpoll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:58:in poll_with_sources' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:94:inpoll' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/poll.rb:119:in block in start' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup.rb:88:inblock in reporting_thread'

And now I can not open a single thread without this error: --- RuntimeError from thread: load threads for thread-index-mode

/var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:615:in find_docid' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:620:infind_doc' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:630:in get_entry' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:236:inblock in build_message' /usr/lib/ruby/2.1.0/monitor.rb:211:in mon_synchronize' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:639:insynchronize' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:236:in build_message' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:230:inblock (2 levels) in each_message_in_thread_for' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:355:in call' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:355:inblock in load_thread_for_message' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:230:in block in each_message_in_thread_for' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:230:ineach' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:230:in each_message_in_thread_for' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:353:inload_thread_for_message' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:345:in block in load_n_threads' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:165:inblock in each_id_by_date' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:288:in block in each_id' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:288:ineach' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:288:in each_id' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:165:ineach_id_by_date' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:340:in load_n_threads' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/modes/thread_index_mode.rb:686:inload_n_threads' (eval):12:in load_n_threads' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/modes/thread_index_mode.rb:670:inblock in load_n_threads_background' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup.rb:88:in block in reporting_thread' --- NoMethodError from thread: load messages for thread-view-mode undefined methodrun' for nil:NilClass (eval):1:in run' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:764:inget_status_and_title' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:262:in draw_screen' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:728:inclear' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:702:in ensure in say' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:702:insay' (eval):1:in say' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/modes/thread_index_mode.rb:113:inblock in select' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup.rb:88:in `block in reporting_thread'

I think it come from the sync-back option, because it happened before and I deleted ~/.sup/xapian/ and sup-sync the whole setup and was working again, but it is long (~24h).

I will try to set the sync-back option to off for test.

Regards, Guillaume.

[GuillaumeSeren]

Even with :sync_back_to_maildir: false it is crashing when openning a thread. --- RuntimeError from thread: load threads for thread-index-mode

/var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:615:in find_docid' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:620:infind_doc' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:630:in get_entry' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:236:inblock in build_message' /usr/lib/ruby/2.1.0/monitor.rb:211:in mon_synchronize' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:639:insynchronize' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:236:in build_message' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:230:inblock (2 levels) in each_message_in_thread_for' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:355:in call' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:355:inblock in load_thread_for_message' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:230:in block in each_message_in_thread_for' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:230:ineach' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:230:in each_message_in_thread_for' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:353:inload_thread_for_message' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:345:in block in load_n_threads' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:165:inblock in each_id_by_date' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:288:in block in each_id' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:288:ineach' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:288:in each_id' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/index.rb:165:ineach_id_by_date' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/thread.rb:340:in load_n_threads' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/modes/thread_index_mode.rb:686:inload_n_threads' (eval):12:in load_n_threads' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/modes/thread_index_mode.rb:670:inblock in load_n_threads_background' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup.rb:88:in block in reporting_thread' --- NoMethodError from thread: load messages for thread-view-mode undefined methodrun' for nil:NilClass (eval):1:in run' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:764:inget_status_and_title' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:262:in draw_screen' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:728:inclear' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:702:in ensure in say' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/buffer.rb:702:insay' (eval):1:in say' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup/modes/thread_index_mode.rb:113:inblock in select' /var/lib/gems/2.1.0/gems/sup-0.20.0/lib/sup.rb:88:in `block in reporting_thread'

Regards, Guillaume.

[ZJvandeWeg]

I just encountered the same error when indexing my mailbox for the first time. (not with sup-sync). After a while I quit sup, as it took to long. Could it be possible that you've interupted the indexing of new threads aswell, which then triggered this error? Or do you have other additional info?

[GuillaumeSeren]

Hey, I still got that issue from time to time, I think the Xapian is getting corrupted, my easy-way to fix it is to rm -rf ~/.sup/xapian and sup-sync the whole thing, it take some time but fix the problem. It am still searching a better way to do it.

[ZJvandeWeg]

Not a fix; but couldn't you sup-dump your index regularly and restore it? Would be faster I guess.

Further; you could export SUP_LOG_LEVEL=debug for better logs to post here next time?

[gauteh]

did you move around the cursor or something while the poll was going on? this has been the source of similar crashes earlier.

[GuillaumeSeren]

@gauteh : Yes I think most of the time the crash append after I moved my cursor, in my setup, sup sit in a tmux tab and I go here from time to time, and it should be the same time sup do it's poll.

@ZJvandeWeg : Yes I will add it to my setup and give a feedback.

[gauteh]

The find_docid error can sometimes be fixed by running sup-sync, the other error can sometimes be avoided by leaving sup alone while the polling operation is updating any lines in the current thread list.

[terotil]

Hit this today. Sup is failing after initial poll every time, no matter what I do. Apparently this is caused by several documents having the same message id. Doesn't that basically mean that your index is corrupted? You'd need to somehow get rid of the duplicate documents so that message id is again unique acros documents.

I tuned the failing method a bit to get more info

  def find_docid id
    docids = term_docids(mkterm(:msgid,id))
    fail "Message #{id} matches several documents: #{docids}" unless docids.size <= 1
    docids.first
  end

It seems to be the same offending id and corresponding doc ids every time Message [email protected] matches several documents: [383102187, 383102188].

How to use the console to poke documents, decide which one to remove and remove it? If nothing else, just to see if it helps (as I expect)?

Instead of crashing, could we try to merge documents to yield at most doc id? What could possibly go wrong? (half jokingly, half serious)