Article delegate-en/4665 of [1-5169] on the server localhost:119
  upper oldest olders older1 this newer1 newers latest
search
[Top/Up] [oldest] - [Older+chunk] - [Newer+chunk] - [newest + Check]
[Reference:<_A4663@delegate-en.ML_>]
Newsgroups: mail-lists.delegate-en

[DeleGate-En] Re: Large emails and POP3
20 Nov 2009 01:25:47 GMT feedback@delegate.org (Yutaka Sato)
The DeleGate Project


Hi Adrian,

In message <_A4663@delegate-en.ML_> on 11/19/09(20:30:15)
you "Adrian Partridge" <pgejabdyi-qjyh54jobnxr.ml@ml.delegate.org> wrote:
 |Attached logfile as requested, generated with a -vd. I've chopped some lines
 |because I keep 14 days worth of emails on our server. Log shows I have 2
 |emails to retrieve, one is 15mb in size. 

Thank you for your log.  It seems showing that your filter program
"spamc" returns almost immediately without receiving the whole message.
So what happens if you use /bin/cat instead of /usr/bin/spamc ?
I tested it with /bin/cat and could not find a problem.

 |If you need anything else, please don't hesitate to ask.

Seeing the log of non-large message without problem might be helpful.
Testing your filter program as "/usr/bin/spamc < a-large-message"
might give us hints too.

Cheers,
Yutaka
--
  9 9   Yutaka Sato <y.sato@delegate.org> http://delegate.org/y.sato/
 ( ~ )  National Institute of Advanced Industrial Science and Technology
_<   >_ 1-1-4 Umezono, Tsukuba, Ibaraki, 305-8568 Japan
Do the more with the less -- B. Fuller

----my test
  % cat cat.cfi
  #!cfi
  MIME-Filter: /bin/cat
  
  % telnet localhost 9999 > test.out
  USER test
  PASS pass
  LIST
  RETR 1
  (wait the finish of "systemFilter" in the log)
  QUIT
  % ls -l test.out
  -rw-r--r-- 1 me      me      15243455 Nov 20 10:07 test.out
  
  % delegated -fv -vd -P9999 SERVER=pop://server FTOCL=cat.cfi
  ...
  11/20 10:06:42.44 [14810] 1+0: CFI/MSGS ---- +OK Mailbox open, 1 messages^M
  11/20 10:06:42.45 [14809] 1+0: POP C-S: LIST^M
  11/20 10:06:42.51 [14809] 1+0: POP S-C[4:5]: +OK Mailbox scan listing follows^M
  11/20 10:06:42.51 [14810] 1+0: CFI/MSGS ---- +OK Mailbox scan listing follows^M
  11/20 10:06:42.58 [14810] 1+0: CFI/MSGS ---- 0 0000000X^M
  11/20 10:06:42.59 [14810] 1+0: CFI/MSGS ---- .^M
  11/20 10:06:46.31 [14809] 1+0: POP C-S: RETR 1^M
  11/20 10:06:46.99 [14809] 1+0: POP S-C[5:3]: +OK 15395456 octets^M
  11/20 10:06:46.99 [14810] 1+0: CFI/MSGS ---- --MESSAGE/mime RETR^M
  11/20 10:06:47.02 [14809] 1+0: TMPFILE(readPart) = (24) /Users/yutaka/delegate/tmp/dg14809.000004.1258679207
  11/20 10:06:47.03 [14809] 1+0: >>>TMPFILE(readPart)>>>a000e004[24]
  11/20 10:07:05.18 [14809] 1+0: ### readPart: got large message (15395310)
  11/20 10:07:05.51 [14810] 1+0: ////////////////////////////
  #!cfi
  MIME-Filter: /bin/cat
  
  11/20 10:07:05.52 [14810] 1+0: ///////// MATCHED //////////
  11/20 10:07:05.52 [14810] 1+0: TMPFILE(CFI-CONV) = (1) /Users/yutaka/delegate/tmp/dg14810.000005.1258679225
  11/20 10:07:05.52 [14810] 1+0: >>>TMPFILE(CFI-CONV)>>>a000e004[1]
  11/20 10:07:08.34 [14810] 1+0: TMPFILE(CFI-MIME-MESSAGE) = (3) /Users/yutaka/delegate/tmp/dg14810.000006.1258679228
  11/20 10:07:08.34 [14810] 1+0: >>>TMPFILE(CFI-MIME-MESSAGE)>>>a000e05c[3]
  11/20 10:07:08.34 [14810] 1+0: systemFilter[with buffered input = 4075]: /bin/cat
  11/20 10:07:08.36 [14810] 1+0: simple_relayf [1 -> 6] = 4075
  11/20 10:07:13.23 [14810] 1+0: simple_relay [1 -> 6] = (15391381 -> 15391381) / 940
  11/20 10:07:13.23 [14810] 1+0: #Sig/CSC finish 200 0 P1 R0 E0 {0 r0 t0} 0/0/0
  11/20 10:07:13.24 [14810] 1+0: wait systemFilter: 14814 ... 14814
  11/20 10:07:13.26 [14810] 1+0: putMIMEmsg: Content-Length: 0 -> 15395375 (15395477 - 102) []
  11/20 10:07:20.03 [14809] 1+0: POP C-S: QUIT^M
  11/20 10:07:20.03 [14809] 1+0: POP S-C[2:0]: +OK Sayonara^M


----your log
In message <_A4663@delegate-en.ML_> on 11/19/09(20:30:15)
you "Adrian Partridge" <pgejabdyi-qjyh54jobnxr.ml@ml.delegate.org> wrote:
 |11/19 11:10:18.54 [4818] 1+0: POP C-S: LIST^M
 |11/19 11:10:18.56 [4818] 1+0: POP S-C[4:5]: +OK POP3 clients that break here, they violate STD53.^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- +OK POP3 clients that break here, they violate STD53.^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- 1 23364^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- 2 4039^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- 3 20703^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- 88 11241^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- 89 28271^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- 90 15113934^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- 91 19914^M
 |11/19 11:10:18.56 [4819] 1+0: CFI/MSGS ---- .^M
 |11/19 11:10:18.58 [4818] 1+0: POP C-S: RETR 90^M
 |11/19 11:10:18.59 [4818] 1+0: POP S-C[5:3]: +OK 15113934 octets follow.^M
 |11/19 11:10:18.59 [4819] 1+0: CFI/MSGS ---- --MESSAGE/mime RETR^M
...
 |11/19 11:10:30.14 [4816] 1+0: AcceptByMain: TIMEOUT(children=1, timeout=15)
 |11/19 11:10:30.15 [4816] 1+0: dirfopen(/var/spool/delegate-spamd/act/restart/_110_,r): 0 [-1]
 |11/19 11:10:30.15 [4816] 1+0: AcceptByMain: start polling(100)[14]...
 |11/19 11:10:30.25 [4816] 1+0: AcceptByMain: start polling(15000)[14]...
 |11/19 11:10:32.09 [4819] 1+0: ////////////////////////////
 |#!cfi
 |MIME-Filter:/usr/bin/spamc
 |
 |11/19 11:10:32.09 [4819] 1+0: ///////// MATCHED //////////
 |11/19 11:10:32.09 [4819] 1+0: TMPFILE(CFI-CONV) = (1) /var/spool/delegate-spamd/tmp/dg4819.000005.1258629032
 |11/19 11:10:32.09 [4819] 1+0: >>>TMPFILE(CFI-CONV)>>>8496dc0[1]
 |11/19 11:10:32.10 [4819] 1+0: TMPFILE(CFI-MIME-MESSAGE) = (4) /var/spool/delegate-spamd/tmp/dg4819.000006.1258629032
 |11/19 11:10:32.10 [4819] 1+0: >>>TMPFILE(CFI-MIME-MESSAGE)>>>8496f28[4]
 |11/19 11:10:32.10 [4819] 1+0: systemFilter[with buffered input = 4067]: /usr/bin/spamc
 |11/19 11:10:32.10 [4819] 1+0: simple_relayf [1 -> 6] = 4067
 |11/19 11:10:32.33 [4819] 1+0: simple_relay [1 -> 6] = (741376 -> 741376) / 46
 |11/19 11:10:32.33 [4819] 1+0: #Sig/CSC finish 805 0 P1 R0 E0 {0 r0 t0} 0/0/0
 |11/19 11:10:32.33 [4819] 1+0: wait systemFilter: 4820 ... 4820
 |11/19 11:10:32.33 [4819] 1+0: putMIMEmsg: Content-Length: 0 -> 0 (0 - 0) []
...

 |11/19 11:13:39.73 [4823] 2+0: POP C-S: LIST^M
 |11/19 11:13:39.75 [4823] 2+0: POP S-C[4:5]: +OK POP3 clients that break here, they violate STD53.^M
 |11/19 11:13:39.75 [4824] 2+0: CFI/MSGS ---- +OK POP3 clients that break here, they violate STD53.^M
 |11/19 11:13:39.75 [4824] 2+0: CFI/MSGS ---- 1 23364^M
 |11/19 11:13:39.75 [4824] 2+0: CFI/MSGS ---- 2 4039^M
 |11/19 11:13:39.75 [4824] 2+0: CFI/MSGS ---- 88 11241^M
 |11/19 11:13:39.75 [4824] 2+0: CFI/MSGS ---- 89 28271^M
 |11/19 11:13:39.75 [4824] 2+0: CFI/MSGS ---- 90 15113934^M
 |11/19 11:13:39.75 [4824] 2+0: CFI/MSGS ---- 91 19914^M
 |11/19 11:13:39.75 [4824] 2+0: CFI/MSGS ---- .^M
 |11/19 11:13:39.76 [4823] 2+0: POP C-S: RETR 90^M
 |11/19 11:13:39.78 [4823] 2+0: POP S-C[5:3]: +OK 15113934 octets follow.^M
 |11/19 11:13:39.78 [4824] 2+0: CFI/MSGS ---- --MESSAGE/mime RETR^M
 |11/19 11:13:53.04 [4824] 2+0: ////////////////////////////
 |#!cfi
 |MIME-Filter:/usr/bin/spamc
 |
 |11/19 11:13:53.04 [4824] 2+0: ///////// MATCHED //////////
 |11/19 11:13:53.04 [4824] 2+0: TMPFILE(CFI-CONV) = (1) /var/spool/delegate-spamd/tmp/dg4824.000005.1258629233
 |11/19 11:13:53.04 [4824] 2+0: >>>TMPFILE(CFI-CONV)>>>8466868[1]
 |11/19 11:13:53.04 [4824] 2+0: TMPFILE(CFI-MIME-MESSAGE) = (4) /var/spool/delegate-spamd/tmp/dg4824.000006.1258629233
 |11/19 11:13:53.04 [4824] 2+0: >>>TMPFILE(CFI-MIME-MESSAGE)>>>84669d0[4]
 |11/19 11:13:53.04 [4824] 2+0: systemFilter[1,4]: /usr/bin/spamc
 |11/19 11:13:53.04 [4824] 2+0: calling mysystem(/usr/bin/spamc)
 |11/19 12:13:53.04 [4830] 2+0: -- Fork(mysystem): 4824 -> 4830
 |11/19 11:13:53.04 [4824] 2+0: 0.003s mysystem(/usr/bin/spamc) 0/0
 |11/19 11:13:53.04 [4824] 2+0: ## xsystem() restore fdi=1 fdo=4
 |11/19 11:13:53.04 [4824] 2+0: ## xsystem() restore fd0=6, fd1=-1
 |11/19 11:13:53.04 [4824] 2+0: putMIMEmsg: Content-Length: 0 -> 0 (0 - 0) []

  admin search upper oldest olders older1 this newer1 newers latest
[Top/Up] [oldest] - [Older+chunk] - [Newer+chunk] - [newest + Check]
@_@V