Subject: bug#71893: 27.1; Gnus pop3 download progress goes over 100%

From: Daniel Bastos <[email-masked]>
Date: Sat, 28 Sep 2024 12:48:10 -0300

Eli Zaretskii <[email-masked]> writes:

>> From: Daniel Bastos <[email-masked]>
>> Date: Thu, 19 Sep 2024 16:13:30 -0300
>> Cc: [email-masked], [email-masked]
>> 
>> On Mon, Sep 9, 2024 at 8:29 PM Daniel Bastos <[email-masked]> wrote:
>> >
>> > On Sat, Aug 31, 2024 at 4:53 AM Eli Zaretskii <[email-masked]> wrote:
>> > > Any progress there?
>> >
>> > I've the 29.3 set up and I have not yet managed to reproduce.
>> 
>> Now I did.  The problem happens in
>> 
>>   GNU Emacs 29.3 (build 2, x86_64-w64-mingw32) of 2024-03-24
>> 
>> too.  Here's what I found in the POP3 before fetching my mail.
>> 
>> +OK 69 messages (2041560 bytes)
>> 1 1243
>> 2 56203
>> 3 5694
>> 4 1858
>> 5 8704
>> 6 2264
>> 7 1626
>> 8 1626
>> 9 1626
>> 10 8704
>> 11 15079
>> 12 15079
>> 13 15079
>> 14 1858
>> 15 6303
>> 16 1303
>> 17 1303
>> 18 1858
>> 19 8704
>> 20 8704
>> 21 8581
>> 22 8704
>> 23 8581
>> 24 13969
>> 25 13969
>> 26 61517
>> 27 9590
>> 28 47193
>> 29 61517
>> 30 47193
>> 31 13969
>> 32 16591
>> 33 1880
>> 34 56203
>> 35 16591
>> 36 16591
>> 37 61517
>> 38 12830
>> 39 56203
>> 40 56203
>> 41 13969
>> 42 16591
>> 43 16591
>> 44 8581
>> 45 1880
>> 46 1880
>> 47 56203
>> 48 12830
>> 49 8704
>> 50 12830
>> 51 61517
>> 52 1880
>> 53 6303
>> 54 6303
>> 55 61517
>> 56 61517
>> 57 61517
>> 58 61517
>> 59 61517
>> 60 61517
>> 61 9590
>> 62 9590
>> 63 237515
>> 64 236784
>> 65 56203
>> 66 56203
>> 67 56203
>> 68 12830
>> 69 17268
>> .
>> +OK Farewell.
>> 
>> If I sum the bytes of each message, I get
>> 
>> %awk '{ sum += $2; } END { print(sum) }' pop3-list.txt
>> 2041560
>> 
>> which is exactly the advertised total at the top.  The Gmail POP3
>> makes minimum sense.  And here's the log after having Gnus fetch all
>> the messages.  (I couldn't keep the beginning lines because the
>> *messages* buffer erased them, but the log shows that Gnus is going
>> well beyond 100%.)
>> 
>> pop3 retrieved 6945KB (340%)
>> [...]
>> pop3 retrieved 9992KB (489%)
>> pop3 retrieved 10386KB (508%)
>> Saving file ~/.pop3-uidl...
>> Wrote c:/Users/x/AppData/Roaming/.pop3-uidl
>> Wrote c:/Users/x/AppData/Roaming/Mail/mail/misc/118
>> Wrote c:/Users/x/AppData/Roaming/Mail/mail/misc/119
>> [...]
>> Wrote c:/Users/x/AppData/Roaming/Mail/mail/misc/186
>> nnml: Reading incoming mail (69 new)...done
>> Reading active file via nnml...done
>> Checking new news...done
>> 
>> Here's a check of how much data I get after having written each
>> message to the file system.
>> 
>> %ls -l | awk '$8 >= 118 && $8 <= 186 { total += $5; print; } END {
>> print(total) }'
>> -rw-rw-rw-   1 x              None         1472 2024-09-19 16:00 118
>> -rw-rw-rw-   1 x              None       876549 2024-09-19 16:00 119
>> -rw-rw-rw-   1 x              None         5925 2024-09-19 16:00 120
>> -rw-rw-rw-   1 x              None          963 2024-09-19 16:00 121
>> -rw-rw-rw-   1 x              None         7307 2024-09-19 16:00 122
>> -rw-rw-rw-   1 x              None         2494 2024-09-19 16:00 123
>> -rw-rw-rw-   1 x              None         1459 2024-09-19 16:00 124
>> -rw-rw-rw-   1 x              None         7773 2024-09-19 16:00 125
>> -rw-rw-rw-   1 x              None         1855 2024-09-19 16:00 126
>> -rw-rw-rw-   1 x              None         2380 2024-09-19 16:00 127
>> -rw-rw-rw-   1 x              None       573608 2024-09-19 16:00 128
>> -rw-rw-rw-   1 x              None        13685 2024-09-19 16:00 129
>> -rw-rw-rw-   1 x              None        15324 2024-09-19 16:00 130
>> -rw-rw-rw-   1 x              None         7416 2024-09-19 16:00 131
>> -rw-rw-rw-   1 x              None      6056691 2024-09-19 16:00 132
>> -rw-rw-rw-   1 x              None         6596 2024-09-19 16:00 133
>> -rw-rw-rw-   1 x              None         1532 2024-09-19 16:00 134
>> -rw-rw-rw-   1 x              None         2088 2024-09-19 16:00 135
>> -rw-rw-rw-   1 x              None         9087 2024-09-19 16:00 136
>> -rw-rw-rw-   1 x              None         1398 2024-09-19 16:00 137
>> -rw-rw-rw-   1 x              None        10892 2024-09-19 16:00 138
>> -rw-rw-rw-   1 x              None         7740 2024-09-19 16:00 139
>> -rw-rw-rw-   1 x              None         3172 2024-09-19 16:00 140
>> -rw-rw-rw-   1 x              None        14922 2024-09-19 16:00 141
>> -rw-rw-rw-   1 x              None        15983 2024-09-19 16:00 142
>> -rw-rw-rw-   1 x              None         9209 2024-09-19 16:00 143
>> -rw-rw-rw-   1 x              None        12690 2024-09-19 16:00 144
>> -rw-rw-rw-   1 x              None        49851 2024-09-19 16:00 145
>> -rw-rw-rw-   1 x              None         3123 2024-09-19 16:00 146
>> -rw-rw-rw-   1 x              None        47433 2024-09-19 16:00 147
>> -rw-rw-rw-   1 x              None        13070 2024-09-19 16:00 148
>> -rw-rw-rw-   1 x              None       186296 2024-09-19 16:00 149
>> -rw-rw-rw-   1 x              None         1108 2024-09-19 16:00 150
>> -rw-rw-rw-   1 x              None       202280 2024-09-19 16:00 151
>> -rw-rw-rw-   1 x              None        16064 2024-09-19 16:00 152
>> -rw-rw-rw-   1 x              None        17431 2024-09-19 16:00 153
>> -rw-rw-rw-   1 x              None        39122 2024-09-19 16:00 154
>> -rw-rw-rw-   1 x              None        10617 2024-09-19 16:00 155
>> -rw-rw-rw-   1 x              None        32890 2024-09-19 16:00 156
>> -rw-rw-rw-   1 x              None        34388 2024-09-19 16:00 157
>> -rw-rw-rw-   1 x              None        14204 2024-09-19 16:00 158
>> -rw-rw-rw-   1 x              None        15540 2024-09-19 16:00 159
>> -rw-rw-rw-   1 x              None        16822 2024-09-19 16:00 160
>> -rw-rw-rw-   1 x              None         8825 2024-09-19 16:00 161
>> -rw-rw-rw-   1 x              None         6727 2024-09-19 16:00 162
>> -rw-rw-rw-   1 x              None         6521 2024-09-19 16:00 163
>> -rw-rw-rw-   1 x              None       934797 2024-09-19 16:00 164
>> -rw-rw-rw-   1 x              None        11879 2024-09-19 16:00 165
>> -rw-rw-rw-   1 x              None         8935 2024-09-19 16:00 166
>> -rw-rw-rw-   1 x              None         3363 2024-09-19 16:00 167
>> -rw-rw-rw-   1 x              None        36427 2024-09-19 16:00 168
>> -rw-rw-rw-   1 x              None         2109 2024-09-19 16:00 169
>> -rw-rw-rw-   1 x              None         1886 2024-09-19 16:00 170
>> -rw-rw-rw-   1 x              None         6534 2024-09-19 16:00 171
>> -rw-rw-rw-   1 x              None        46503 2024-09-19 16:00 172
>> -rw-rw-rw-   1 x              None        44079 2024-09-19 16:00 173
>> -rw-rw-rw-   1 x              None        54344 2024-09-19 16:00 174
>> -rw-rw-rw-   1 x              None        52465 2024-09-19 16:00 175
>> -rw-rw-rw-   1 x              None        62311 2024-09-19 16:00 176
>> -rw-rw-rw-   1 x              None        61752 2024-09-19 16:00 177
>> -rw-rw-rw-   1 x              None         8929 2024-09-19 16:00 178
>> -rw-rw-rw-   1 x              None         9823 2024-09-19 16:00 179
>> -rw-rw-rw-   1 x              None       237754 2024-09-19 16:00 180
>> -rw-rw-rw-   1 x              None       237022 2024-09-19 16:00 181
>> -rw-rw-rw-   1 x              None        49595 2024-09-19 16:00 182
>> -rw-rw-rw-   1 x              None        53055 2024-09-19 16:00 183
>> -rw-rw-rw-   1 x              None        56433 2024-09-19 16:00 184
>> -rw-rw-rw-   1 x              None        13062 2024-09-19 16:00 185
>> -rw-rw-rw-   1 x              None        17499 2024-09-19 16:00 186
>> 10403078
>> 
>> I get a lot more data---10,403,078 bytes.  So it makes me feel that
>> Gnus is not at fault here; that it's the POP3 server that sometimes
>> advertises a total amount, but ends up providing a lot more than the
>> advertised value.  I wouldn't assume this is an obvious bug of any
>> POP3 server, but it's what the evidence seems to suggest---that the
>> Gmail POP3 server says one thing and does another.
>
> I'm not an expert on POP3 protocol -- does it report bytes or
> characters?

It says 

   +OK 69 messages (2041560 bytes)

when we issue the LIST command.  For the number to the right of the
message index, I would think it's bytes as well: if I add each one of
those numbers, I end up with 2041560, which is the total byte amount
advertised in the +OK-line.

> Also, do the files created by Gnus have Unix or DOS EOL format?
> If the latter, could the difference be explained by the added CR
> characters?

Gnus might be even adding data to these messages such as headers---I
don't know.  I would not expect to read the files on the file system and
find the same byte amount advertised by the POP3 server.  However, the
report I gave previously shows a factor of 5 increase in the total byte
downloaded---we go from 2 MiB to 10 MiB---, so I would not think this is
a matter of added CR characters nor headers added by Gnus.  (It's too
much extra data that's appearing from I don't know where.)

> Eventually, if the problem is with the server, what do we want to do
> with this bug report? what _can_ we do?

Right now I can't see what can we do.  By the way, this is not a bug
report: Gnus doesn't appear to be at fault.  This is a request for help:
I'm puzzled.  While the evidence is against the POP3 server, it's hard
to think that a POP3 server would be shipped with such an obvious bug.

I'm going to compare the behavior using other e-mail clients.  I need to
find one that lets me watch the download progress like Gnus does.