Subject: Re: [sup-talk] Bug: Xapian exception after having polled

From: Gaute Hope <[email-masked]>
Date: Sun, 4 Oct 2009 20:56:31 +0200

Still having problems, but got a bit more output, see attached exception.log

[sup.git](next) $ git log --oneline -6
a209178 more id assertions
0eee097 Merge branch 'master' into next
93b5552 more release-script updates
f56badb Merge branch 'master' into next
b9071e5 change date for 0.9 release
9a5c0d1 Merge branch 'save-all-attachments' into next

- gaute

On Sun, Oct 4, 2009 at 8:45 PM, Rich Lane <[email-masked]> wrote:
> Ok, I've attached a patch with more assertions. Also, can you try with a clean
> checkout of next and see if the problem still occurs?
>

---

From: Gaute Hope <[email-masked]>
Date: Tue, 06 Oct 2009 00:01:18 +0200

Did a 'sup-sync --changed -o' and the problem seems to be gone. 

- gaute

Excerpts from Gaute Hope's message of su. okt. 04 21:20:50 +0200 2009:
> Still the same..
> 
> (run without '-n' then P this time, thats the reason for the longer exception..)
> 
> [sup.git](next-nil) $ git log --oneline -4
> 7e99810 for your confirmation..
> eafea2b more id assertions
> On Sun, Oct 4, 2009 at 9:03 PM, Rich Lane <[email-masked]> wrote:
> > Oops, sorry, bad assertions. Please move the two in
> > self.build_from_source to the end of load_from_source!.
> >
> > Excerpts from Gaute Hope's message of Sun Oct 04 14:56:31 -0400 2009:
> >> --- RuntimeError from thread: main
> >> @id nil
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/message.rb:342:in
> >> `build_from_source'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:160:in
> >> `each_message_from'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/maildir.rb:160:in `each'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/maildir.rb:157:in `upto'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/maildir.rb:157:in `each'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:560:in `send'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:560:in `__pass'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:547:in `method_missing'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:154:in
> >> `each_message_from'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:108:in `do_poll'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:96:in `each'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:96:in `do_poll'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:95:in `synchronize'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:95:in `do_poll'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:520:in `send'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:520:in `method_missing'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/modes/poll-mode.rb:15:in `poll'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:47:in `poll_with_sources'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:62:in `poll'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:520:in `send'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:520:in `method_missing'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/bin/sup:287
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:73:in `reporting_thread'
> >> /home/gaute/.gem/ruby/1.8/gems/sup-999/bin/sup:287
> >> /home/gaute/.gem/ruby/1.8/bin/sup:19:in `load'
> >> /home/gaute/.gem/ruby/1.8/bin/sup:19
> >
> --- RuntimeError from thread: poll after loading inbox
> @id nil
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/message.rb:254:in
> `load_from_source!'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/message.rb:342:in
> `build_from_source'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:160:in
> `each_message_from'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/source.rb:104:in `each'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:560:in `send'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:560:in `__pass'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:547:in `method_missing'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:154:in
> `each_message_from'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:108:in `do_poll'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:96:in `each'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:96:in `do_poll'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:95:in `synchronize'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:95:in `do_poll'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:520:in `send'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:520:in `method_missing'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/modes/poll-mode.rb:15:in `poll'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:47:in `poll_with_sources'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/poll.rb:62:in `poll'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:520:in `send'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/util.rb:520:in `method_missing'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/bin/sup:197
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:77:in `reporting_thread'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:75:in `initialize'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:75:in `new'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:75:in `reporting_thread'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/bin/sup:197
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/modes/thread-index-mode.rb:669:in
>  `call'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/modes/thread-index-mode.rb:669:in
>  `__unprotected_load_threads'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/modes/thread-index-mode.rb:610:in
>  `call'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/modes/thread-index-mode.rb:610:in
>  `load_n_threads_background'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:77:in `reporting_thread'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:75:in `initialize'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:75:in `new'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup.rb:75:in `reporting_thread'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/modes/thread-index-mode.rb:608:in
>  `load_n_threads_background'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/lib/sup/modes/thread-index-mode.rb:679:in
>  `__unprotected_load_threads'
> (eval):12:in `load_threads'
> /home/gaute/.gem/ruby/1.8/gems/sup-999/bin/sup:197
> /home/gaute/.gem/ruby/1.8/bin/sup:19:in `load'
> /home/gaute/.gem/ruby/1.8/bin/sup:19

---

From: William Morgan <[email-masked]>
Date: Tue, 06 Oct 2009 07:59:07 -0700

Reformatted excerpts from Guillaume Quintard's message of 2009-10-06:
> [Tue Oct 06 11:22:55 +0200 2009] hook: error running hook: cannot
> generate tempfile `/tmp/12016-9-attachments/389068.html'
> [Tue Oct 06 11:22:55 +0200 2009] hook:
> /usr/lib/ruby/1.8/tempfile.rb:52:in `initialize'
> ./lib/sup/message-chunks.rb:149:in `new'
> ./lib/sup/message-chunks.rb:149:in `write_to_disk'
> ./lib/sup/message-chunks.rb:105:in `initialize'
> ./lib/sup/hook.rb:51:in `call'
> ./lib/sup/hook.rb:51:in `filename'
> /home/shivan/.sup/hooks/mime-decode.rb:4:in `__run'

I think that's an unrelated issue, but it's weird that it couldn't
create that file in /tmp. Are you out of disk space, missing a /tmp
directory, or something weird like that?
-- 
William <[email-masked]>
_______________________________________________
sup-talk mailing list
[email-masked]
http://rubyforge.org/mailman/listinfo/sup-talk

---

From: Guillaume Quintard <[email-masked]>
Date: Tue, 6 Oct 2009 12:14:43 +0200

> Did a 'sup-sync --changed -o' and the problem seems to be gone.

It doesn't for me. During sup-sync I get this:

[Tue Oct 06 11:22:55 +0200 2009] hook: error running hook: cannot
generate tempfile `/tmp/12016-9-attachments/389068.html'
[Tue Oct 06 11:22:55 +0200 2009] hook:
/usr/lib/ruby/1.8/tempfile.rb:52:in `initialize'
./lib/sup/message-chunks.rb:149:in `new'
./lib/sup/message-chunks.rb:149:in `write_to_disk'
./lib/sup/message-chunks.rb:105:in `initialize'
./lib/sup/hook.rb:51:in `call'
./lib/sup/hook.rb:51:in `filename'
/home/shivan/.sup/hooks/mime-decode.rb:4:in `__run'
./lib/sup/hook.rb:42:in `__run'
./lib/sup/hook.rb:82:in `run'
./lib/sup/util.rb:520:in `send'
./lib/sup/util.rb:520:in `method_missing'
./lib/sup/message-chunks.rb:104:in `initialize'
./lib/sup/message.rb:503:in `new'
./lib/sup/message.rb:503:in `message_to_chunks'
./lib/sup/message.rb:435:in `message_to_chunks'
./lib/sup/message.rb:435:in `map'
./lib/sup/message.rb:435:in `message_to_chunks'
./lib/sup/message.rb:239:in `load_from_source!'
./lib/sup/message.rb:335:in `build_from_source'
./lib/sup/poll.rb:160:in `each_message_from'
./lib/sup/source.rb:104:in `each'
./lib/sup/util.rb:560:in `send'
./lib/sup/util.rb:560:in `__pass'
./lib/sup/util.rb:547:in `method_missing'
./lib/sup/poll.rb:154:in `each_message_from'
./lib/sup/util.rb:520:in `send'
./lib/sup/util.rb:520:in `method_missing'
bin/sup-sync:146
bin/sup-sync:141:in `each'
bin/sup-sync:141

I got rid of the hooks, ran sup-sync again, the message goes away, but
I still get:

--- RuntimeError from thread: load threads for thread-index-mode
wrong id called on nil
./lib/sup.rb:17:in `id'
./lib/sup/modes/thread-index-mode.rb:225:in `update'
./lib/sup/hook.rb:121:in `sort_by'
./lib/sup/modes/thread-index-mode.rb:225:in `each'
./lib/sup/modes/thread-index-mode.rb:225:in `sort_by'
./lib/sup/modes/thread-index-mode.rb:225:in `update'
./lib/sup/modes/thread-index-mode.rb:223:in `synchronize'
./lib/sup/modes/thread-index-mode.rb:223:in `update'
./lib/sup/modes/thread-index-mode.rb:637:in `__unprotected_load_n_threads'
(eval):12:in `load_n_threads'
./lib/sup/modes/thread-index-mode.rb:609:in `load_n_threads_background'
./lib/sup.rb:77:in `reporting_thread'
./lib/sup.rb:75:in `initialize'
./lib/sup.rb:75:in `new'
./lib/sup.rb:75:in `reporting_thread'
./lib/sup/modes/thread-index-mode.rb:608:in `load_n_threads_background'
./lib/sup/modes/thread-index-mode.rb:679:in `__unprotected_load_threads'
(eval):12:in `load_threads'
bin/sup:197

upon loading

-- 
Guillaume

---

From: Rich Lane <[email-masked]>
Date: Sat, 03 Oct 2009 14:22:34 -0400

Apply the attached patch and let us know what the new backtrace is.

---

From: Gaute Hope <[email-masked]>
Date: Sun, 4 Oct 2009 12:15:50 +0200

Greetings,

Applied; fails at the same point, new backtrace attached.

(ps: your patch fails with 'git am' might be the Author: line that
should be a From:)

- gaute

---

From: Rich Lane <[email-masked]>
Date: Sun, 04 Oct 2009 14:45:55 -0400

---

From: Rich Lane <[email-masked]>
Date: Sun, 04 Oct 2009 15:03:51 -0400

---

From: Gaute Hope <[email-masked]>
Date: Tue, 06 Oct 2009 15:34:51 +0200

> --- RuntimeError from thread: load threads for thread-index-mode

I was getting a slightly different error:

- gaute

---

From: Gaute Hope <[email-masked]>
Date: Sun, 4 Oct 2009 21:20:50 +0200

Still the same..

- gaute

>> /home/gaute/.gem/ruby/1.8/bin/sup:19
From 7e99810ebf7d3f361c31236c3c131c1c794f8076 Mon Sep 17 00:00:00 2001
From: Gaute Hope <[email-masked]>
Date: Sun, 4 Oct 2009 21:17:23 +0200
Subject: [PATCH] for your confirmation..

---
 lib/sup/message.rb |    5 ++---
 1 files changed, 2 insertions(+), 3 deletions(-)

diff --git a/lib/sup/message.rb b/lib/sup/message.rb
index 7592b51..fad9866 100644
--- a/lib/sup/message.rb
+++ b/lib/sup/message.rb
@@ -242,7 +242,6 @@ class Message
           parse_header @source.load_header(@source_info)
           fail "id nil after parse_header" unless @id
           message_to_chunks @source.load_message(@source_info)
-          fail "id nil after message_to_chunks" unless @id
         rescue SourceError, SocketError => e
           warn "problem getting messages from #{@source}: #{e.message}"
           ## we need force_to_top here otherwise this window will cover
@@ -252,6 +251,8 @@ class Message
           [Chunk::Text.new(error_message(e.message).split("\n"))]
         end
       end
+    fail "@id nil" unless @id
+    fail "id nil" unless id
   end
 
   def error_message msg
@@ -339,8 +340,6 @@ EOS
   def self.build_from_source source, source_info
     m = Message.new :source => source, :source_info => source_info
     m.load_from_source!
-    fail "@id nil" unless @id
-    fail "id nil" unless id
     m
   end
 
-- 
1.6.4.4