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

From: Daniel Bastos <[email-masked]>
Date: Thu, 19 Sep 2024 16:13:30 -0300

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.

(*) How I generated the log in *messages*

I added a (message "...") call to the procedure pop3-wait-for-messages.

(defun pop3-wait-for-messages (process count total-size start-point)
  (while (> count 0)
    (goto-char start-point)
    (while (or (and (re-search-forward "^\\+OK" nil t)
    (or (not total-size)
(re-search-forward "^\\.\r?\n" nil t)))
       (re-search-forward "^-ERR " nil t))
      (cl-decf count)
      (setq start-point (point)))
    (unless (memq (process-status process) '(open run))
      (error "pop3 process died"))
    (when total-size
      (let ((size 0))
(goto-char (point-min))
(while (re-search-forward "^\\+OK.*\n" nil t)
  (setq size (+ size (- (point))
(if (re-search-forward "^\\.\r?\n" nil 'move)
    (match-beginning 0)
  (point)))))
(message "pop3 retrieved %dKB (%d%%)"
(truncate (/ size 1000))
(truncate (* (/ (* size 1.0) total-size) 100)))))
    (pop3-accept-process-output process))
  start-point)