Petar Bogdanovic
petar@smokva.net
Wed May 27 22:44:42 UTC 2009
On Wed, May 27, 2009 at 10:54:22PM +0200, Petar Bogdanovic wrote: > On Wed, May 27, 2009 at 08:02:32PM +0000, Vernon Schryver wrote: > > Does snooping with tcpdump or ethereal show that the DCC requests are > > going out? Being answered? > > I'll try 1.3.104 again today or during the next few days, check the > traffic with tcpdump and report back. Lets begin with `re-resolve on first use' vs. `cdcc rtt'. map contains names which were not resolved during the initial installation (due to lack of DNS): # spamassassin -D <gtube.txt 2>&1 | grep -i dcc (...) [669] dbg: dcc: dccifd is available: /var/dcc/dccifd [669] dbg: dcc: dccifd got response: X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 # grep dcc /var/log/maillog dccifd[501]: 1.3.104 listening to /var/dcc/dccifd for ASCII protocol dccifd[501]: no working DCC servers dcc1.dcc-servers.net dcc2.dcc-servers.net dcc3.dcc-servers.net ... at 127.0.0.1 dccifd[501]: continue not asking DCC 124 seconds after failure Ok, lets wait. # cdcc info # 05/27/09 23:32:28 CEST /var/dcc/map # Re-resolve names after 01:23:53 Check RTTs after 23:38:53 # 1 total, 0 working servers # skipping asking DCC server 4 seconds more Only 4 more seconds.. # cdcc info # 05/27/09 23:32:36 CEST /var/dcc/map # Re-resolve names after 01:23:53 Check RTTs after 23:38:53 # 1 total, 0 working servers Ready? Lets try. # spamassassin -D <gtube.txt 2>&1 | grep -i dcc (...) [669] dbg: dcc: dccifd is available: /var/dcc/dccifd [669] dbg: dcc: dccifd got response: X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 # cdcc info # 05/27/09 23:32:46 CEST /var/dcc/map # Re-resolve names after 01:23:53 Check RTTs after 23:38:53 # 1 total, 0 working servers # skipping asking DCC server 508 seconds more Not really. # cdcc rtt # 05/27/09 23:35:42 CEST /var/dcc/map # Re-resolve names after 01:35:37 Check RTTs after 23:50:42 # 1347.14 ms threshold, 1222.97 ms average 12 total, 10 working servers IPv6 on version=3 dcc1.dcc-servers.net,- RTT+1000 ms anon # 137.208.8.26,- wuwien ID 1290 # protocol version 8 # 100% of 3 requests ok 1031.91+1000 ms RTT 100 ms queue wait # 209.169.14.26,- x.dcc-servers ID 104 # 100% of 1 requests ok 322.07+1000 ms RTT 100 ms queue wait # 209.169.14.29,- x.dcc-servers ID 104 # 100% of 1 requests ok 321.08+1000 ms RTT 100 ms queue wait dcc2.dcc-servers.net,- RTT+1000 ms anon # *195.20.8.232,- EATSERVER ID 1166 # 100% of 1 requests ok 122.97+1000 ms RTT 100 ms queue wait # 203.81.36.6,- PacNet-SG ID 1358 # 100% of 2 requests ok 569.62+1000 ms RTT 200 ms queue wait dcc3.dcc-servers.net,- RTT+1000 ms anon # 194.228.41.73,- CTc-dcc1 ID 1030 # protocol version 8 # 100% of 1 requests ok 134.76+1000 ms RTT 100 ms queue wait # 209.169.14.27,- x.dcc-servers ID 104 # 100% of 1 requests ok 322.75+1000 ms RTT 100 ms queue wait dcc4.dcc-servers.net,- RTT+1000 ms anon # 152.20.253.5,- dcc.uncw.edu ID 1201 # 100% of 1 requests ok 247.14+1000 ms RTT 100 ms queue wait # 194.228.41.13,- CTc-dcc2 ID 1031 # protocol version 8 # 100% of 1 requests ok 135.25+1000 ms RTT 100 ms queue wait dcc5.dcc-servers.net,- RTT+1000 ms anon # 209.34.225.42,- # not answering # 216.240.97.12,- dmv.com ID 1181 # protocol version 8 # 100% of 1 requests ok 211.29+1000 ms RTT 100 ms queue wait All right, thats better. Lets retry SpamAssassin. # spamassassin -D <gtube.txt 2>&1 | grep -i dcc (...) [554] dbg: dcc: dccifd is available: /var/dcc/dccifd [554] dbg: dcc: dccifd check timed out after 8 secs. # grep dcc /var/log/maillog dccifd[501]: no DCC answer from dcc4.dcc-servers.net (152.20.253.5,6277) after 6050 ms dccifd[501]: write(MTA socket,76): Broken pipe As expected. Lets run SpamAssassin a couple of times. # for i in $(seq 1 100); do spamassassin -D <gtube.txt 2>&1 | grep -i dcc; done (...) Minutes later.. # cdcc info # 05/27/09 23:42:52 CEST /var/dcc/map # Re-resolve names after 01:35:37 Check RTTs after 23:50:42 # 8000.00 ms threshold, 1222.97 ms average 12 total, 10 working servers IPv6 on version=3 dcc1.dcc-servers.net,- RTT+1000 ms anon # 137.208.8.26,- wuwien ID 1290 # protocol version 8 # 27% of 11 requests ok 4000.00+1000 ms RTT 100 ms queue wait # 209.169.14.26,- x.dcc-servers ID 104 # 20% of 5 requests ok 4000.00+1000 ms RTT 100 ms queue wait # 209.169.14.29,- x.dcc-servers ID 104 # 20% of 5 requests ok 4000.00+1000 ms RTT 100 ms queue wait dcc2.dcc-servers.net,- RTT+1000 ms anon # 195.20.8.232,- EATSERVER ID 1166 # 8% of 13 requests ok 4000.00+1000 ms RTT 100 ms queue wait # 203.81.36.6,- PacNet-SG ID 1358 # 33% of 6 requests ok 4000.00+1000 ms RTT 200 ms queue wait dcc3.dcc-servers.net,- RTT+1000 ms anon # 194.228.41.73,- CTc-dcc1 ID 1030 # protocol version 8 # 8% of 13 requests ok 4000.00+1000 ms RTT 100 ms queue wait # 209.169.14.27,- x.dcc-servers ID 104 # 20% of 5 requests ok 4000.00+1000 ms RTT 100 ms queue wait dcc4.dcc-servers.net,- RTT+1000 ms anon # 152.20.253.5,- dcc.uncw.edu ID 1201 # 8% of 13 requests ok 4000.00+1000 ms RTT 100 ms queue wait # 194.228.41.13,- CTc-dcc2 ID 1031 # protocol version 8 # 8% of 13 requests ok 4000.00+1000 ms RTT 100 ms queue wait dcc5.dcc-servers.net,- RTT+1000 ms anon # 209.34.225.42,- # not answering # 216.240.97.12,- dmv.com ID 1181 # protocol version 8 # 8% of 13 requests ok 4000.00+1000 ms RTT 100 ms queue wait It seems that I don't get any answers at all. Lets tcpdump one session. # spamassassin -D <gtube.txt 2>&1 | grep -i dcc (...) [1047] dbg: dcc: dccifd is available: /var/dcc/dccifd [1047] dbg: dcc: dccifd check timed out after 8 secs. # tcpdump -vvvv -i rtk0 udp port 6277 tcpdump: listening on rtk0, link-type EN10MB (Ethernet), capture size 96 bytes 23:50:10.094242 IP (... length: 180) MYHOST.65500 > dcc-1.eatserver.nl.6277: UDP, length: 152 23:50:10.217154 IP (... length: 116) dcc-1.eatserver.nl.6277 > MYHOST.65500: UDP, length: 88 23:50:10.444220 IP (... length: 180) MYHOST.65500 > dcc-1.eatserver.nl.6277: UDP, length: 152 23:50:10.569212 IP (... length: 116) dcc-1.eatserver.nl.6277 > MYHOST.65500: UDP, length: 88 23:50:11.044208 IP (... length: 180) MYHOST.65500 > dcc-1.eatserver.nl.6277: UDP, length: 152 23:50:11.165145 IP (... length: 116) dcc-1.eatserver.nl.6277 > MYHOST.65500: UDP, length: 88 23:50:12.144210 IP (... length: 180) MYHOST.65500 > dcc-1.eatserver.nl.6277: UDP, length: 152 23:50:12.265192 IP (... length: 116) dcc-1.eatserver.nl.6277 > MYHOST.65500: UDP, length: 88 23:50:16.144244 IP (... length: 180) MYHOST.65500 > h4-vjs.colo.indra.com.6277: UDP, length: 152 23:50:16.374800 IP (... length: 116) h4-vjs.colo.indra.com.6277 > MYHOST.65500: UDP, length: 88 23:50:16.494252 IP (... length: 180) MYHOST.65500 > h4-vjs.colo.indra.com.6277: UDP, length: 152 23:50:16.726501 IP (... length: 116) h4-vjs.colo.indra.com.6277 > MYHOST.65500: UDP, length: 88 23:50:17.094246 IP (... length: 180) MYHOST.65500 > h4-vjs.colo.indra.com.6277: UDP, length: 152 23:50:17.352498 IP (... length: 116) h4-vjs.colo.indra.com.6277 > MYHOST.65500: UDP, length: 88 23:50:18.194257 IP (... length: 180) MYHOST.65500 > h4-vjs.colo.indra.com.6277: UDP, length: 152 23:50:18.447587 IP (... length: 116) h4-vjs.colo.indra.com.6277 > MYHOST.65500: UDP, length: 88 I can't really read that output but it seems to me that I'm actually getting an answer every time I'm asking for one. Lets see (log) what ipfilter sees. pass out log proto udp from any to any port = 6277 keep state # DCC ^^^ ipmon[317]: 23:54:09.999847 rtk0 @0:16 p MYHOST,65500 -> 209.169.14.27,6277 PR udp len 20 180 K-S OUT ipmon[317]: 23:54:10.237437 rtk0 @0:16 p 209.169.14.27,6277 -> MYHOST,65500 PR udp len 20 116 K-S IN ipmon[317]: 23:54:10.349835 rtk0 @0:16 p MYHOST,65500 -> 209.169.14.27,6277 PR udp len 20 180 K-S OUT ipmon[317]: 23:54:10.583213 rtk0 @0:16 p 209.169.14.27,6277 -> MYHOST,65500 PR udp len 20 116 K-S IN ipmon[317]: 23:54:10.949831 rtk0 @0:16 p MYHOST,65500 -> 209.169.14.27,6277 PR udp len 20 180 K-S OUT ipmon[317]: 23:54:11.180647 rtk0 @0:16 p 209.169.14.27,6277 -> MYHOST,65500 PR udp len 20 116 K-S IN ipmon[317]: 23:54:12.049829 rtk0 @0:16 p MYHOST,65500 -> 209.169.14.27,6277 PR udp len 20 180 K-S OUT ipmon[317]: 23:54:12.278444 rtk0 @0:16 p 209.169.14.27,6277 -> MYHOST,65500 PR udp len 20 116 K-S IN ipmon[317]: 23:54:16.049879 rtk0 @0:16 p MYHOST,65500 -> 203.81.36.6,6277 PR udp len 20 180 K-S OUT ipmon[317]: 23:54:16.619082 rtk0 @0:16 p 203.81.36.6,6277 -> MYHOST,65500 PR udp len 20 116 K-S IN ipmon[317]: 23:54:16.719552 rtk0 @0:16 p MYHOST,65500 -> 203.81.36.6,6277 PR udp len 20 180 K-S OUT ipmon[317]: 23:54:17.288365 rtk0 @0:16 p 203.81.36.6,6277 -> MYHOST,65500 PR udp len 20 116 K-S IN ipmon[317]: 23:54:17.958900 rtk0 @0:16 p MYHOST,65500 -> 203.81.36.6,6277 PR udp len 20 180 K-S OUT ipmon[317]: 23:54:18.527800 rtk0 @0:16 p 203.81.36.6,6277 -> MYHOST,65500 PR udp len 20 116 K-S IN ipmon[317]: 23:54:20.337624 rtk0 @0:16 p MYHOST,65500 -> 203.81.36.6,6277 PR udp len 20 180 K-S OUT ipmon[317]: 23:54:20.906424 rtk0 @0:16 p 203.81.36.6,6277 -> MYHOST,65500 PR udp len 20 116 K-S IN Again, this just seems good to *me*. Why am I using SpamAssassin anyway? Lets try dccproc a couple of times. # for i in $(seq 1 100); do dccproc <gtube.txt | grep -i dcc; done no DCC answer from dcc2.dcc-servers.net (195.20.8.232,6277) after 15838 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 no DCC answer from dcc1.dcc-servers.net (209.169.14.29,6277) after 15882 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 no DCC answer from dcc4.dcc-servers.net (152.20.253.5,6277) after 15882 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 no DCC answer from dcc1.dcc-servers.net (209.169.14.26,6277) after 16000 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 no DCC answer from dcc3.dcc-servers.net (209.169.14.27,6277) after 15883 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 no DCC answer from dcc1.dcc-servers.net (137.208.8.26,6277) after 15840 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 no DCC answer from dcc4.dcc-servers.net (194.228.41.13,6277) after 15844 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 no DCC answer from dcc5.dcc-servers.net (216.240.97.12,6277) after 15875 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 no DCC answer from dcc3.dcc-servers.net (194.228.41.73,6277) after 15974 ms X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 continue not asking DCC 64 seconds after failure X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 continue not asking DCC 64 seconds after failure X-DCC--Metrics: MYHOST 0; Body=1 Fuz1=1 Fuz2=1 continue not asking DCC 64 seconds after failure (...) That's all I have for now. And I don't get it. As soon as I replace 1.3.104 with 1.3.103 all this suddenly works. Petar Bogdanovic
More information about the DCC
mailing list
