Ticket #3000 (closed defect: fixed)

Opened 12 months ago

Last modified 3 weeks ago

Deleting >50k messages from IMAP boxes fails with Fatal error:

Reported by: myon Owned by: brendan
Priority: minor Milestone: 1.6
Component: IMAP Version: 1.5.17
Keywords: patch Cc: jhawk@…

Description (last modified by brendan) (diff)

Hi,

I'm trying to delete some 200k messages from a 240k IMAP folder.
Tagging ~m1-10000 and deleting/expunging works. For larger selections
(I first tried 200k and then 50k), mutt fails with

Fatal error: word too long

and closes the folder.

Mutt version 1.5.17, both tarball and hg HEAD.

Christoph

Attachments

socketwrite.diff (1.4 kB) - added by Patrick Welche 6 weeks ago.
Added by email2trac

Change History

Changed 6 months ago by brendan

  • priority changed from major to minor
  • summary changed from Deleting >50k messages from IMAP boxes fails with Fatal error: word too long to Deleting >50k messages from IMAP boxes fails with Fatal error:
  • component changed from mutt to MIME
  • version set to 1.5.17
  • milestone set to 1.6

Changed 6 months ago by jhawk

  • cc jhawk@… added

It's exactly this that prompted my request for a deletion log (#2895); I think this is actually a server-side problem, but that doesn't mean that mutt shouldn't work around it, because many users don't have much control over their servers...

Why is this component MIME and not IMAP?

Changed 3 months ago by pdmef

  • owner changed from mutt-dev to brendan
  • component changed from MIME to IMAP

It's been a while, but is there any chance you can get a debug log?

It would help trace the socket traffic (e.g. help adjusting the code to send out multiple smalller commands instead of one huge, or see if the command sent is complete at all, etc.)

Changed 3 months ago by jhawk

What debugging level is appropriate? Opening my large mailbox with -d 3 produces a 106mb logfile. Having tagged a few thousand message s ofr deletion and then hit $, my logfile ends with:

> a0025 FETCH 215455:215455 (UID FLAGS INTERNALDATE RFC822.SIZE BODY.PEEK[HEADER
.FIELDS (DATE FROM SUBJECT TO CC MESSAGE-ID REFERENCES CONTENT-TYPE CONTENT-DESC
RIPTION IN-REPLY-TO REPLY-TO LINES LIST-POST X-LABEL X-Spam-Score)])
< * 215455 FETCH (FLAGS (\Recent) UID 2057859 INTERNALDATE "22-Aug-2008 17:48:37
 -0400" RFC822.SIZE 2646 BODY[HEADER.FIELDS (DATE FROM SUBJECT TO CC MESSAGE-ID 
REFERENCES CONTENT-TYPE CONTENT-DESCRIPTION IN-REPLY-TO REPLY-TO LINES LIST-POST
 X-LABEL X-Spam-Score)] {442}
Handling FETCH
FETCH response ignored for this message
imap_read_literal: reading 442 bytes
< )
parse_parameters: `charset="iso-8859-2"'
parse_parameter: `charset' = `iso-8859-2'
< a0025 OK Completed
Overriding UIDNEXT: 2057859 -> 2057860
> a0026 NOOP
< a0026 OK Completed
> a0027 UID STORE 1771854:1771855,1771986,1772192,1772324,1772329:1772330,177236
3,1772557:1772558,1772759,1772827,1772843,1772970,1772985,1773010,1773125,177316
1,1773188,1773200,1773203:1773206,1773298,1773341,1773383,1773663,1773841,177393
5,1773951,1774088,1774266,1774432,1774591,1774628,1774906,1774940,1774983,177505

...

8,2055571,2055746,2055798,2055822,2055830,2055845,2055934,2056097,2056271,205636
8,2056379,2056508,2056516,2056533,2056647,2056656,2056694,2056770,2056813,205683
1,2056858,2056940,2057157,2057375,2057390,2057425,2057434,2057456,2057459:205746
0,2057498,2057596,2057627,2057668,2057672,2057719,2057842 +FLAGS.SILENT (\Delete
d)
< * BYE Fatal error: word too long
Handling BYE
Fatal error: word too long
mutt_free_body: Not unlinking EmailMessage.pdf.
mutt_free_body: Not unlinking Documentation.pdf.
mutt_free_body: Not unlinking Certification.pdf.
mutt_free_body: Not unlinking information.pdf.
mutt_free_body: Not unlinking information.pdf.
mutt_free_body: Not unlinking clientcare.pdf.
mutt_free_body: Not unlinking clientcare.pdf.
mutt_free_body: Not unlinking clientcare.pdf.
Mailbox closed
imap_exec: command failed: * BYE Fatal error: word too long
Expunge failed

Do you need more?

Changed 3 months ago by brendan

  • status changed from new to assigned
  • description modified (diff)

Nope, that's fine. I'll try to put together a patch to clamp command size, at least for flag storage which is the only thing that currently makes very long commands.

Changed 3 months ago by Brendan Cully <brendan@…>

  • status changed from assigned to closed
  • resolution set to fixed

(In [e68f79fef249]) Split long IMAP commands for the benefit of lazy servers (closes #3000). Also touches lots of old, hairy code. Likely to wake sleeping dogs.

Changed 3 months ago by John Hawkinson

Awesome. This seems to work and at least passes the smoke test.
I'll pound on it a bit more. It does make it really obvious
that "Expunging messages from server..." needs to use mutt_progress*,
but that's minor.


Thanks.
--jhawk

Changed 3 months ago by pdmef

  • status changed from closed to reopened
  • resolution fixed deleted

Reopen ticket, the fix in [e68f79fef249] got reverted in [1d94905ad00b].

Changed 3 months ago by Brendan Cully <brendan@…>

  • status changed from reopened to closed
  • resolution set to fixed

(In [e0f0a7915711]) Use sorted headers in imap_exec_msgset. Fixes [e68f79fef249]. Closes #3000 again.

Changed 3 months ago by jhawk

  • status changed from closed to reopened
  • resolution fixed deleted

I built the 8/31 snapshot and got a core dump after hitting "$" in imap_sync_mailbox:

program terminated by signal SEGV (no mapping at the fault address)
Current function is imap_sync_mailbox
(dbx) where
=>[1] imap_sync_mailbox(ctx = 0xe9b60, expunge = 0, index_hint = 0x329f5), line 1279 in "imap.c"
  [2] mx_sync_mailbox(ctx = 0xe9b60, index_hint = 0xffbfd5dc), line 1159 in "mx.c"
  [3] mutt_index_menu(), line 1023 in "curs_main.c"
  [4] main(argc = 0, argv = 0xffbfed9c), line 1018 in "main.c"
(dbx) list -10
 1269           idata->state = IMAP_AUTHENTICATED;
 1270           goto out;
 1271         }
 1272       }
 1273       else
 1274         mutt_error _("Error saving flags");
 1275       goto out;
 1276     }
 1277   
 1278     for (n = 0; n < ctx->msgcount; n++)
 1279       ctx->hdrs[n]->changed = 0;
 1280     ctx->changed = 0;
 1281
 1282     /* We must send an EXPUNGE command if we're not closing. */
 1283     if (expunge && !(ctx->closing) &&
 1284         mutt_bit_isset(idata->ctx->rights, M_ACL_DELETE))
 1285     {
 1286       mutt_message _("Expunging messages from server...");
 1287       /* Set expunge bit so we don't get spurious reopened messages */
 1288       idata->reopen |= IMAP_EXPUNGE_EXPECTED;
(dbx) print n
n = 207349
(dbx) print ctx->hdrs[n]
ctx->hdrs[n] = (nil)
(dbx) print ctx->hdrs
ctx->hdrs = 0x9f19b90
(dbx) print ctx->hdrs[n-1]   
ctx->hdrs[n-1] = 0x78596d8   
(dbx) print *(ctx->hdrs[n-1])
*ctx->hdrs[n-1] = {
    security        = 0
    mime            = 0
    flagged         = 0
    tagged          = 0
    deleted         = 0
    changed         = 0
    attach_del      = 0
    old             = 1U
    read            = 0
    expired         = 0
    superseded      = 0
    replied         = 0
    subject_changed = 0
    threaded        = 0
    display_subject = 0
    recip_valid     = 0
    active          = 1U
    trash           = 0
    zhours          = 7U
    zminutes        = 0
    zoccident       = 0
    searched        = 0
    matched         = 0
    attach_valid    = 0
    collapsed       = 0
    limited         = 0
    num_hidden      = 0
    recipient       = 0
    pair            = 0
    date_sent       = 1208793756
    received        = 1208794681
    offset          = 0
    lines           = 0
    index           = 156001
   msgno           = 207348
    virtual         = -1
    score           = 0
    env             = 0x7859740
    content         = 0x7859798
    path            = (nil)
    tree            = (nil)
    thread          = (nil)
    attach_total    = 0
    data            = 0x7858db8
    maildir_flags   = (nil)
}
(dbx) 

Any more details you need? I'll keep the core file around for a while.

Changed 3 months ago by Brendan Cully

On Sunday, 31 August 2008 at 17:21, Mutt wrote:

Hrm. It would be helpful to see the .muttdebug0 for this case. Can you
reproduce it? Send it to me personally and I'll figure out what part
of it needs to be in the bug log. Thanks!

Changed 3 months ago by John Hawkinson

Mutt <fleas@mutt.org> wrote on Sun, 31 Aug 2008
at 17:34:48 -0000 in <045.d33d7e2d3e34dcd5d768e7ce30a83901@mutt.org>:


Well, it takes 30+ minutes to open this imap mailbox, and things
are a bit interesting.

First observation is I tried to delete 5k messages before the initial
crash, and it looks like it managed to sync almost all of the delete
flags to the server.

Hitting '$','n' returns instantly and doesn't crash (no surprise).

Hitting '$','y', it starts to expunge, and fails with a bogus Kerberos
error:

{{{
Updating progress: 207300
5> a0010 EXPUNGE
5< * 17 EXPUNGE
Handling EXPUNGE
5< * 17 EXPUNGE
Handling EXPUNGE
5< * 200 EXPUNGE
...
5< * 122570 EXPUNGE
Handling EXPUNGE
SASL: Time is out of bounds (krb_rd_req)
SASL decode failed: generic failure
imap_cmd_step: Error reading server response.
mutt_free_body: Not unlinking EmailMessage.pdf.
mutt_free_body: Not unlinking Documentation.pdf.
mutt_free_body: Not unlinking Certification.pdf.
mutt_free_body: Not unlinking information.pdf.
mutt_free_body: Not unlinking information.pdf.
mutt_free_body: Not unlinking clientcare.pdf.
mutt_free_body: Not unlinking clientcare.pdf.
mutt_free_body: Not unlinking clientcare.pdf.
Mailbox closed
mutt_socket_close: Attempt to close closed connection.
imap_exec: command failed: * 122583 EXPU
imap_sync_mailbox: EXPUNGE failed [* 122583 EXPU]

No mailbox is open.
}}}

Normally "Time is out of bounds (krb_rd_req)" means one of the server
or the client's clock was off by 300 seconds. Both the client and
server are ntp synced and neither experienced any strange events
during this period, so as far as I can tell the error is completely
bogus. (Also, generally you only get this error at the beginning of a
Kerberos authentiation, when tickets are presented, not later on.)

I hope figuring this out won't involve digging down into the SASL
layerr.

Reopening the mailbox now (another 30+ minutes), I'll try deleting
another 1k messages or so and see if we can trigger the original
(the core dump earlier today) bug.

--jhawk

Changed 3 months ago by John Hawkinson

|  Can you reproduce it?

Apparently not. I can't remember whether the deletion that caused
the core dump (5k msgs out of 200k) was a '$','y' or a '$','n',
but large deletions don't seem to trigger this problem again.

A 1k deletion with '$','n' did not crash.

A 10k deletion with '$','y' did not crash, but did fail again with
the bogus "SASL: Time is out of bounds (krb_rd_req)."

Someone over here suggested "I'm betting that was actually a timeout
and someone used the wrong error code somewhere," which seems
plausible.

I guess I can try a 10k '$','n' deletion, but I doubt it'll
crash. (That'll be another 40 minutes; I won't send more mail
unless I find anything...)

[This mailbox loaded with spam, in case you're wondering. I occasionally
slog through it with pine because of this mutt bug, but not very
often....]


So, apparently not.

Is there any other information to try to get out of the core dump?
I guess one observation is that it looks like the deleted message
where the ctx->hdrs[n] defeference failed happned to be msgcount-1,
which suggests the problem has to do with memory allocation and housekeeping
and fenceposts and soforth:

(dbx) print ctx->msgcount
ctx->msgcount = 207350
(dbx) print n
n = 207349
(dbx) 

--jhawk

Changed 3 months ago by brendan

  • description modified (diff)

the fencepost observation is worth a closer look. The time problem is weirder, but I wonder how long it takes to do such a large expunge. Rereading cmd_parse_expunge, it's O(ctx->msgcount) for every single EXPUNGE message (it's pretty naive code). On a huge mailbox like this one, that could really add up.

I don't think this bug is actually to do with the command splitting code though. It may need merging with one of the other IMAP segfault bugs.

Changed 2 months ago by Patrick Welche

On Tue, Sep 02, 2008 at 06:36:04PM -0000, Mutt wrote:

This is excellent - no more "word too long"!

I just tried to tag 10651 messages, and copy them to another imap folder.
The last command in the debug log looks good:

4< a0024 OK [COPYUID 1220965724 319674,319685,319688,319699,319738,319755,319765,319767,319793,319796,319803,319871,319926,320054,320061:320062,320064,320066:320067,320098,320131,320141,320238,320471,320482,320506,320513,320529,320557,320562,320568,320572:320573,320576,320579,320582,320584,320590,320594,320598,320606:320607,320617,320627,320654,320667,320674,320738,320741,320745,320768,320774,320776,320781,320884:320885,321049,321051,321060,321062,321065,321073,321079,321126,321129,321139,321144:321145,321150,321199,321210,321362,321377,321430,321461,321484:321485,321496,321585,321587,321594:321595,321597:321598,321602,321605,321617,321624,321626,321628,321634,321639,321646,321649,321658,321665,321687,321695,321750,321763:321764,321770,321773,321836,321848,321887,321900:321901,321915,321950:321951,321975:321976,322001,322020,322107,322120,322128,322132,322134,322195,322212,322223,322405,322418,322429,322506:322507,322559,322567,322653,322717,322731,322741:322742,322749,322813,322819,322825:322826,322828,322833,322873,322876,322894,322911,322987,323052,323155,323212:323214,323244,323357:323358,323400,323402,323405,323409 4588:4746] Completed

so the splitting is successful

After that, nothing happens though: I still see

Copying to imap://localhost/http...

in mutt's status line.

Any idea what to try?

Cheers,

Patrick
(today's source)

Changed 2 months ago by Patrick Welche

On Mon, Sep 15, 2008 at 10:14:40AM -0000, Mutt wrote:

.. on closer examination:

4< a0090 OK [COPYUID 1220965724 319674,319685,319688,319699,319738,319755,319765,319767,319793,319796,319803,319871,319926,320054,320061:320062,320064,320066:320067,320098,320131,320141,320238,320471,320482,320506,320513,320529,320557,320562,320568,320572:320573,320576,320579,320582,320584,320590,320594,320598,320606:320607,320617,320627,320654,320667,320674,320738,320741,320745,320768,320774,320776,320781,320884:320885,321049,321051,321060,321062,321065,321073,321079,321126,321129,321139,321144:321145,321150,321199,321210,321362,321377,321430,321461,321484:321485,321496,321585,321587,321594:321595,321597:321598,321602,321605,321617,321624,321626,321628,321634,321639,321646,321649,321658,321665,321687,321695,321750,321763:321764,321770,321773,321836,321848,321887,321900:321901,321915,321950:321951,321975:321976,322001,322020,322107,322120,322128,322132,322134,322195,322212,322223,322405,322418,322429,322506:322507,322559,322567,322653,322717,322731,322741:322742,322749,322813,322819,322825:322826,322828,322833,322873,322876,
322894,322911,322987,323052,323155,323212:323214,323244,323357:323358,323400,323402,323405,323409 6961:7119] Completed

so the cyrus imap server has just written messages up to 323409

mutt asked it to do that back at:

a0090 UID COPY 319674,319685,319688,319699,319738,319755,319765:319767,319793:319796,319803,319871,319926,320054,320061:320067,320098,320131:320141,320238,320471,320482,320506:320513,320529,320557,320562,320568:320584,320590:320594,320598,320606:320607,320617,320627,320654:320667,320674,320738:320741,320745,320768,320774:320776,320781,320884:320885,321049:321051,321060,321062:321065,321073,321079,321126,321129,321139,321144:321145,321150,321199,321210,321362,321377,321430,321461,321484:321485,321496,321585:321587,321594:321598,321602,321605,321617,321624,321626,321628,321634,321639,321646,321649,321658,321665,321687,321695,321750,321763:321764,321770:321773,321836,321848,321887,321900:321901,321915,321950:321951,321975:321976,322001,322020,322107,322120,322128,322132:322134,322195,322212,322223,322405,322418,322429,322506:322507,322559,322567,322653,322717,322731,322741:322742,322749,322813:322819,322825:322826,322828:322833,322873,322876,322894,322911,322987,323052,323155,323212:323214,323244,323357:323358,323400:323409 "http"^M

(it's odd that the UIDs above are nearly the same, but not exactly the same as
those in the request?)

but then this next request is never acknowledged by the server.

a0091 UID COPY 323413,323418,323422,323435,323586,323722,323763,323900,323903,323916,323919,323942,323946,323958,323961,323968,323970,323974,323976,323981,323994,324009,324065,324104,324125,324136,324148:324150,324155,324161,324231,324345,324361,324396,324407,324424,324459,324474,324511,324571,324591:324592,324778,324783,324795,324858:324859,324980,325043,325079:325080,325366,325403,325415,325418,325438,325478,325530,325626,325632,325683,325709,325713,325723,325736,325746:325760,325762,325765,325771,325787,325792,325803,325805,325820,325853,325857,325880,325887,325905,325929,325935,325944:325945,325977,326081,326137:326142,326160:326161,326188,326202,326225,326237:326243,326251,326266,326277,326336,326362,326380:326381,326393,326400,326411,326422,326447,326522,326545,326677:326680,326686,326701:326704,326714,326718:326719,326758,326775,326799,326857:326865,326868,326906,326961:326963,326974,326996,327020,327081,327119,327129,327135,327147,327160,327184:327187,327225:327227,327233:327241,327251,327263,327341:327342,327388 "http"^M
mutt_socket_write: ERROR: wrote 4091 of 16716 bytes!
4< a0076 OK [COPYUID 1220965724 72479,72540,72841,72869,72886,72894,72908,72982:72983,73012,73036,73055,87830,88345,88476,88525,89395,89407:89408,89416,89455,89524,89558,90037,90202,90292,90298,90321,90331,90360,90430,90438,90460:90461,90470,90474,90485,90501,90677,90979,91575,96070,96074,96125,96330,96332,96345:96346,96349,96356,96380,96400,96404,96953,98015,98668,99209,99229,99234,99243,99248,99267,99357,99364,99625,99627,99646,99650,99652:99653,99673,99683,99818,99843:99844,99875,99891:99892,99896,99903,99
imap_cmd_step: grew buffer to 1024 bytes
4< 914,99927,99931,99986,100033,100046,100134,100252,100275,100301,100363,100410,100451,100459,100461,100470,101013,101019,101021,101069,101102,101131,101143:101144,101155,101157,101159:101160,101184,101233,101247,101276:101277,101462,101708,101800,101806,101867,101870,102051,102063,102067,102069,102072:102073,102084,102087,102090,102105,102115,102120:102121,102125,102157,102168:102169,102172:102173,102200,102206,102215,102228,102239,102294,102297,102303,102314,102325,102346,102357,102409,102763,102800,102835,
imap_cmd_step: grew buffer to 1536 bytes
4< 102873,102901,103017,103022,103035,103038,103058,103110:103111 4747:4909] Completed

mutt carries on sending requests, so appears to have recovered from the
ERROR, but the server doesn't seem to agree?

Thoughts?

Cheers,

Patrick

Changed 2 months ago by Patrick Welche

On Tue, Sep 16, 2008 at 04:37:28PM -0000, Mutt wrote:

Just to rule out ancient buggy imap server, I upgraded cyrus imapd from
2.2beta to today's cvs, but got the same symptoms. It seems that mutt
can't recover from

  mutt_socket_write: ERROR: wrote 4091 of 16715 bytes!

(then
imap_cmd_step: grew buffer to 1024 bytes
imap_cmd_step: grew buffer to 1536 bytes
)
but the message sent to cyrus when the ERROR happened is not acknowledged
by cyrus, nor any subsequent sent messages.

cyrus is stuck in select() waiting to getc
mutt is stuck in read() (raw_socket_read)

So, both are trying to read :-/

Changed 6 weeks ago by Patrick Welche

Added by email2trac

Changed 6 weeks ago by Patrick Welche

On Tue, Sep 16, 2008 at 04:37:28PM -0000, Mutt wrote:

The attached patch solves the problem. In fact it works so well that
on my test copying 7915 messages from one folder to another, cyrus imap
gave up because the receiving mailfolder's cache file grew to 2G which
it tried to mmap.

Cheers,

Patrick

Changed 6 weeks ago by brendan

Interesting. Mutt shouldn't be using non-blocking I/O, so writes shouldn't need retrying. That makes this patch magical. It'd be great if we could figure out why this works :)

Changed 6 weeks ago by brendan

Patrick, are you using openssl or gnutls to access your mailbox? And which revision of mutt are you building? Thanks.

Changed 6 weeks ago by pdmef

  • keywords patch added

Changed 6 weeks ago by Patrick Welche

On Tue, Oct 07, 2008 at 04:35:26PM -0000, Mutt wrote:

I am not using anything special to access the mailbox (mutt and server
running on same box, mutt -f imap://localhost/INBOX, no TLS set up),
and I am using HEAD of a few days ago (what's the mercurial equivalent
of cvs status mutt_socket.c?, hg status just says "M" which is fair enough.
My mutt_socket.c contains

#ifdef HAVE_SYS_TIME_H
#include <sys/time.h>
#endif

which I think is one of your more recent commits)


Now my .muttdebug0 has

a0062 UID COPY 321461,321484:321485,321496,321585:321587,321594:321598,321602,32
1605,321617,321624,321626,321628,321634,321639,321646,321649,321658,321665,32168
7,321695,321750,321763:321764,321770:321773,321836,321848,321887,321900:321901,3
21915,321950:321951,321975:321976,322001,322020,322107,322120,322128,322132:3221
34,322195,322212,322223,322405,322418,322429,322506:322507,322559,322567,322653,
322717,322731,322741:322742,322749,322813:322819,322825:322826,322828:322833,322
839,322873,322876,322894,322911,322987,323052,323155,323181,323191:323193,323212
:323214,323244,323309,323311,323339,323353,323357:323358,323368,323400:323409,32
3413,323418,323422,323435,323586,323722,323763,323900,323903,323916,323919,32394
2,323946,323958,323961,323968,323970,323974,323976,323981,323994,324009,324065,3
24104,324125,324136,324148:324150,324155,324161,324231,324345,324361,324396,3244
07,324424,324459,324474,324511,324571,324591:324592,324778,324783,324795,324858:
324859,324980,325043,325079:325080,325366,325403,325407,325410,325415,325418 "ht
tp"
mutt_socket_write: short write, now writing the rest
mutt_socket_write: short write, now writing the rest
mutt_socket_write: short write, now writing the rest
mutt_socket_write: short write, now writing the rest
mutt_socket_write: short write, now writing the rest

in it rather than getting stuck with both mutt and cyrus wanting to read.
I am actually surprised how often I get the "short write" message - with
the old code, I think I would only have received the ERROR when I received
more than one consecutive "short write" in the new code.

Cheers,

Patrick

Changed 6 weeks ago by Patrick Welche

On Tue, Oct 07, 2008 at 04:24:34PM -0000, Mutt wrote:

You are also right to be wary - I may have ended up copying multiple copies...
Checking...

P

Changed 6 weeks ago by exg

On which system does it happen?

Changed 5 weeks ago by brendan

The cvs status equivalent is hg parents. Can you tell us which OS/libc you're running? I am still confused about why mutt's blocking write would return short writes at all.

Changed 5 weeks ago by brendan

One more thing - can you say what auth method you use? I wonder if maybe the SASL layer is interfering. By the way, your patch appears to return only the length of the last write, rather than the total amount written. But it doesn't look like this should matter.

Changed 5 weeks ago by Patrick Welche

I'm using

changeset:   5530:ffefb446142c
branch:      HEAD
tag:         tip
user:        Rocco Rutte <pdmef@gmx.net>
date:        Thu Sep 18 08:28:51 2008 +0200
summary:     Fix compiler warnings

NetBSD-4.99.73/i386

I thought that with my patch, mutt_socket_write_d could only return 0 or -1.
(Or possibly a negative number, but that would say that write wrote more than
len) (Is mutt_socket_write_d meant to return the number of bytes writen? I
only seem to see tests for <0 or ==-1. If so, just save len before the
while loop and return it if rc!=-1)

set imap_authenticators="digest-md5:cram-md5"

and digest-md5 is always the one used.

Note that all works well for less than about 300 messages - you really have
to move around lots of messages to see these problems...


Cheers,

Patrick

Changed 5 weeks ago by Matthias Andree

Mutt <fleas@mutt.org> writes:


Not having looked at the actual issue or patch, I'd say the socket's
send buffer size matters here.  With synchronous (i. e.  blocking)
writes, you can only toss a TCP send buffer's size worth of command
bytes down the pipe. Then you need to start fetching replies so the
server can send replies and drains your write buffer at the same
time. You may need to make up for truncated commands and complete
writing a line so as not to lock up.

Stuffing 50k message positions (let alone UIDs) will easily exceed
typical TCP send buffer sizes. If you're not fetching replies due to the
blocking write, the whole setup will deadlock until timeouts strike.

Check the STREAMING or PIPELINING RFCs (the number of which I forget),
there is one that documents the requirements, but I forgot the context,
might have been POP3, IMAP, NNTP, thereabouts.

Changed 5 weeks ago by brendan

I'm not sure about your diagnosis. First of all, I'd be pretty surprised if the send buffer were 4K -- I'd expect 64K+, I think, which should be well over the total amount of data mutt is pipelining. Second, when the buffer is exceeded, the sender should simply block, not return a short writes. Finally, it's up to the IMAP server to read from its incoming queue to uncork the pipeline. There's no application-level requirement that I can think of for mutt to read anything until it's finished sending its command data.

Changed 5 weeks ago by cameron

"Second, when the buffer is exceeded, the sender should simply block, not return a short writes."

If the buffer is nearly full, the write may put in what it can. UNIX write(2) calls have always been permitted to return short writes. _Is_ there anything watching for the return traffic?

You shouldn't need to "start fetching replies so the server can send replies and drains your write buffer at the same time" (TCP will happily send ACKs without outbound data), but if you don't collect the incoming replies it will only buffer so much inbound data and will block the sender eventually. If the sender's blocked trying to send to you and not reading your own sends, you too will block in the same way.

I feel like I describing stuff you already know though...

Changed 5 weeks ago by Patrick Welche

On Sat, Oct 18, 2008 at 12:58:48AM -0000, Mutt wrote:

Exactly, and at this point mutt prints an error and bails out, rather
than try to send the part of the buffer which wasn't written.

(Patch seeks to address this)

(The last few messages seem to make this all sound far more complicated
than it really is...)

Changed 5 weeks ago by Brendan Cully <brendan@…>

(In [ea800edbd056]) Handle short writes in mutt_socket_write_d. See #3000. Apparently even blocking I/O with signals masked can sometimes return early. Based on a patch by Patrick Welche.

Changed 3 weeks ago by brendan

  • status changed from reopened to closed
  • resolution set to fixed

I'm closing this one. I think the segfault and the long delay in expunging are probably worth separate bugs, but the original complaint in this one should be resolved.

Note: See TracTickets for help on using tickets.