I opened this bug report <br><br><a href="https://bugzilla.andrew.cmu.edu/show_bug.cgi?id=2986">https://bugzilla.andrew.cmu.edu/show_bug.cgi?id=2986</a><br><br>Regards<br><br><div><span class="gmail_quote">On 8/13/07, <b class="gmail_sendername">
Alain Spineux</b> <<a href="mailto:aspineux@gmail.com">aspineux@gmail.com</a>> wrote:</span><blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;">
<br>Something strange append with my cyrus-imap 2.3.8 from openpkg imapd-2.3.8-20070720<br><br>When I CLOSE a mailbox, (after a SELECT), the server die and close the connection !<br>Look the FIN  (F) packet at 16:14:25.869642

<br><br>Here are the relevant the cyrus log (around 16:14:25)<br><br>cyrmaster.log:Aug 13 16:14:25 eg01 <error> master[32578]: process 21432 exited, signaled to death by 11<br>cyrmaster.log:Aug 13 16:14:25 eg01 <debug> master[32578]: service imap pid 21432 in BUSY state: terminated abnormally
<br>cyrmaster.log:Aug 13 16:14:25 eg01 <debug> master[21531]: about to exec /kolab/bin/imapd<br><br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484170<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: abort_txn: aborting txn 2147484170
<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484171<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mystore: reusing txn 2147484171<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mycommit: committing txn 2147484171
<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484172<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: abort_txn: aborting txn 2147484172<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484173
<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mystore: reusing txn 2147484173<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mycommit: committing txn 2147484173<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484174
<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: abort_txn: aborting txn 2147484174<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484175<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mystore: reusing txn 2147484175
<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mycommit: committing txn 2147484175<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484176<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: abort_txn: aborting txn 2147484176
<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484177<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mystore: reusing txn 2147484177<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mycommit: committing txn 2147484177
<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484178<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: abort_txn: aborting txn 2147484178<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: myfetch: starting txn 2147484179
<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mystore: reusing txn 2147484179<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: mycommit: committing txn 2147484179<br>imapd.log:Aug 13 16:14:25 eg01 <debug> imap[21432]: open: user manager opened 
<a href="mailto:user/donald.duck@gamma.loc" target="_blank" onclick="return top.js.OpenExtLink(window,event,this)">user/donald.duck@gamma.loc</a><br><br>Here is the ASCII's tcpdump <br><br>ODPO12 SETACL "<a href="mailto:user/donald.duck@gamma.loc" target="_blank" onclick="return top.js.OpenExtLink(window,event,this)">
user/donald.duck@gamma.loc</a>" manager lrd..
<br>16:14:25.857715 IP eg01.imap > eg01.55867: P 457:478(21) ack 544 win 256 <nop,nop,timestamp 47451731 47451730><br>ODPO12 OK Completed..<br>16:14:25.858710 IP eg01.55867 > eg01.imap: P 544:588(44) ack 478 win 290 <nop,nop,timestamp 47451732 47451731>
<br>ODPO13 SELECT "<a href="mailto:user/donald.duck@gamma.loc" target="_blank" onclick="return top.js.OpenExtLink(window,event,this)">user/donald.duck@gamma.loc</a>"..<br>16:14:25.859297 IP eg01.imap > eg01.55867
: P 478:777(299) ack 588 win 256 <nop,nop,timestamp 47451732 47451732>
<br>* FLAGS (\Answered \Flagged \Draft \Deleted \Seen)..<br>* OK [PERMANENTFLAGS (\Deleted)]  ..<br>* 0 EXISTS..<br>* 0 RECENT..<br>* OK [UIDVALIDITY 1187010780]  ..<br>* OK [UIDNEXT 2]  ..<br>* OK [NOMODSEQ] Sorry, modsequences have not been enabled on this mailbox..
<br>* OK [URLMECH INTERNAL]..<br>ODPO13 OK [READ-WRITE] Completed..<br>16:14:25.860638 IP eg01.55867 > eg01.imap: P 588:611(23) ack 777 win 299 <nop,nop,timestamp 47451732 47451732><br>ODPO14 UID SEARCH ALL..<br>

16:14:25.860913 IP eg01.imap > eg01.55867: P 777:831(54) ack 611 win 256 <nop,nop,timestamp 47451732 47451732><br>* SEARCH..<br>ODPO14 OK Completed (0 msgs in 0.000 secs)..<br>16:14:25.862171 IP eg01.55867 > 
eg01.imap
: P 611:625(14) ack 831 win 299 <nop,nop,timestamp 47451732 47451732><br>ODPO15 CLOSE..<br>16:14:25.869642 IP eg01.imap > eg01.55867: F 831:831(0) ack 625 win 256 <nop,nop,timestamp 47451734 47451732><br>16:14:
25.906271 IP eg01.55867 > eg01.imap: . ack 832 win 299 <nop,nop,timestamp 47451744 47451734><br>16:14:25.933508 IP eg01.55867 > eg01.imap: P 625:638(13) ack 832 win 299 <nop,nop,timestamp 47451750 47451734>
<br>ODPO16 NOOP..<br>16:14:25.933539 IP eg01.imap > eg01.55867: R 3474995568:3474995568(0) win 0<br>16:14:25.934034 IP eg01.55871 > eg01.imap: S 3508738700:3508738700(0) win 32792 <mss 16396,sackOK,timestamp 47451750 0,nop,wscale 7>
<br>16:14:25.934062 IP eg01.imap > eg01.55871: S 3501230146:3501230146(0) ack 3508738701 win 32768 <mss 16396,sackOK,timestamp 47451750 47451750,nop,wscale 7><br>16:14:25.934081 IP eg01.55871 > eg01.imap: . ack 1 win 257 <nop,nop,timestamp 47451750 47451750>
<br>16:14:25.964179 IP eg01.imap > eg01.55871: P 1:117(116) ack 1 win 256 <nop,nop,timestamp 47451758 47451750><br>* OK [CAPABILITY IMAP4 IMAP4rev1 LITERAL+ ID STARTTLS] eg01 Cyrus IMAP4 v2.3.8-openpkg server ready..
<br>16:14:25.964335 IP eg01.55871 > eg01.imap: . ack 117 win 257 <nop,nop,timestamp 47451758 47451758><br>16:14:25.964595 IP eg01.55871 > eg01.imap: P 1:19(18) ack 117 win 257 <nop,nop,timestamp 47451758 47451758>
<br>IECD0 CAPABILITY..<br><br><br>Here is another transcript and logs, but the SEARCH returned some emails, I delete them then CLOSE and still get the same error<br><br><br>cyrmaster.log:Aug 13 16:41:12 eg01 <error> master[32578]: process 21531 exited, signaled to death by 11
<br>cyrmaster.log:Aug 13 16:41:12 eg01 <debug> master[32578]: service imap pid 21531 in BUSY state: terminated abnormally<br><br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484246
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: reusing txn 2147484246<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: reusing txn 2147484246<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mycommit: committing txn 2147484246
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: starting txn 2147484247<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: committing txn 2147484247<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484248
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: abort_txn: aborting txn 2147484248<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484249<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: reusing txn 2147484249
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mycommit: committing txn 2147484249<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484250<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: abort_txn: aborting txn 2147484250
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484251<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: reusing txn 2147484251<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mycommit: committing txn 2147484251
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484252<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: abort_txn: aborting txn 2147484252<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484253
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: reusing txn 2147484253<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mycommit: committing txn 2147484253<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484254
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: abort_txn: aborting txn 2147484254<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484255<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: reusing txn 2147484255
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mycommit: committing txn 2147484255<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484256<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: abort_txn: aborting txn 2147484256
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484257<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: reusing txn 2147484257<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mycommit: committing txn 2147484257
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484258<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: abort_txn: aborting txn 2147484258<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: myfetch: starting txn 2147484259
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mystore: reusing txn 2147484259<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mycommit: committing txn 2147484259<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: open: user manager opened 
<a href="mailto:user/alain.spineux@gamma.loc" target="_blank" onclick="return top.js.OpenExtLink(window,event,this)">user/alain.spineux@gamma.loc</a><br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: SQUAT failed to open index file
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: SQUAT failed
<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mailbox_expunge: removing mail gamma.loc!user.alain^spineux:1<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mailbox_expunge: removing mail gamma.loc!user.alain

^spineux:2<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mailbox_expunge: removing mail gamma.loc!user.alain^spineux:3<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[21531]: mailbox_expunge: removing mail 
gamma.loc!user.alain^spineux:4<br>imapd.log:Aug 13 16:41:12 eg01 <notice> imap[21531]: Expunged 4 messages from gamma.loc!user.alain^spineux<br>imapd.log:Aug 13 16:41:12 eg01 <debug> imap[22414]: accepted connection
<br><br><br><br>16:41:12.876898 IP eg01.55871 > eg01.imap: P 640:698(58) ack 355 win 282 <nop,nop,timestamp 47853460 47853460><br>IECD15 SETACL "<a href="mailto:user/alain.spineux@gamma.loc" target="_blank" onclick="return top.js.OpenExtLink(window,event,this)">
user/alain.spineux@gamma.loc
</a>" manager lrd..<br>16:41:12.884891 IP eg01.imap > eg01.55871: P 355:376(21) ack 698 win 256 <nop,nop,timestamp 47853462 47853460><br>IECD15 OK Completed..<br>16:41:12.885813 IP eg01.55871 > eg01.imap
: P 698:744(46) ack 376 win 282 <nop,nop,timestamp 47853462 47853462>
<br>IECD16 SELECT "<a href="mailto:user/alain.spineux@gamma.loc" target="_blank" onclick="return top.js.OpenExtLink(window,event,this)">user/alain.spineux@gamma.loc</a>"..<br>16:41:12.886621 IP eg01.imap > eg01.55871
: P 376:694(318) ack 744 win 256 <nop,nop,timestamp 47853463 47853462>
<br>* FLAGS (\Answered \Flagged \Draft \Deleted \Seen)..<br>* OK [PERMANENTFLAGS (\Deleted)]  ..<br>* 4 EXISTS..<br>* 4 RECENT..<br>* OK [UNSEEN 1]  ..<br>* OK [UIDVALIDITY 1186973198]  ..<br>* OK [UIDNEXT 5]  ..<br>* OK [NOMODSEQ] Sorry, modsequences have not been enabled on this mailbox..
<br>* OK [URLMECH INTERNAL]..<br>IECD16 OK [READ-WRITE] Completed..<br>16:41:12.887616 IP eg01.55871 > eg01.imap: P 744:767(23) ack 694 win 290 <nop,nop,timestamp 47853463 47853463><br>IECD17 UID SEARCH ALL..<br>

16:41:12.888135 IP eg01.imap > eg01.55871: P 694:756(62) ack 767 win 256 <nop,nop,timestamp 47853463 47853463><br>* SEARCH 1 2 3 4..<br>IECD17 OK Completed (4 msgs in 0.000 secs)..<br>16:41:12.888711 IP eg01.55871

 > eg01.imap: P 767:840(73) ack 756 win 290 <nop,nop,timestamp 47853463 47853463><br>IECD18 UID COPY 1,2,3,4 <a href="mailto:user/catchall.gamma.loc/alain.spineux@gamma.loc" target="_blank" onclick="return top.js.OpenExtLink(window,event,this)">
user/catchall.gamma.loc/alain.spineux@gamma.loc
</a>..<br>16:41:12.903778 IP eg01.imap > eg01.55871: P 756:777(21) ack 840 win 256 <nop,nop,timestamp 47853467 47853463><br>IECD18 OK Completed..<br>16:41:12.904178 IP eg01.55871 > eg01.imap: P 840:884(44) ack 777 win 290 <nop,nop,timestamp 47853467 47853467>
<br>IECD19 UID STORE 1,2,3,4 +FLAGS (\Deleted)..<br>16:41:12.911896 IP eg01.imap > eg01.55871: P 777:974(197) ack 884 win 256 <nop,nop,timestamp 47853469 47853467><br>* 1 FETCH (FLAGS (\Recent \Deleted) UID 1)..
<br>
* 2 FETCH (FLAGS (\Recent \Deleted) UID 2)..<br>* 3 FETCH (FLAGS (\Recent \Deleted) UID 3)..<br>* 4 FETCH (FLAGS (\Recent \Deleted) UID 4)..<br>IECD19 OK Completed..<br>16:41:12.913147 IP eg01.55871 > eg01.imap: P 884:898(14) ack 974 win 299 <nop,nop,timestamp 47853469 47853469>
<br>IECD20 CLOSE..<br>16:41:12.931917 IP eg01.imap > eg01.55871: F 974:974(0) ack 898 win 256 <nop,nop,timestamp 47853474 47853469><br>16:41:12.970379 IP eg01.55871 > eg01.imap: . ack 975 win 299 <nop,nop,timestamp 47853484 47853474>
<br>16:41:12.989151 IP eg01.55871 > eg01.imap: P 898:911(13) ack 975 win 299 <nop,nop,timestamp 47853488 47853474><br>IECD21 NOOP..<br>16:41:12.989193 IP eg01.imap > eg01.55871: R 3501231896:3501231896(0) win 0
<br><br>Any idea ?<br><span class="sg"><br><br clear="all"><br>-- <br>Alain Spineux<br>aspineux gmail com<br>May the sources be with you
</span></blockquote></div><br><br clear="all"><br>-- <br>Alain Spineux<br>aspineux gmail com<br>May the sources be with you