You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@spamassassin.apache.org by Justin Mason <jm...@jmason.org> on 2008/09/13 12:09:33 UTC

distributed mass-checks hanging again

take a look at /export/home/nitemc/jm on the zone.  could be something to do with
using a Solaris machine as a slave, since it started failing once I replaced
vmsa with spamassassin2.zones.apache.org.

snippet:

+ /local/perl586/bin/perl mass-check --noisy --progress --cs_ssl --server spamassassin.zones.apache.org.:38891 '-
-run_post_scan=./rule-qa/nightly-slaves-start mccli@spamassassin2.zones.apache.org:-j4 jm@talon1.pccc.com:-j16 jm
@infiltrator.stdlib.net:-j16' --reuse --cache --cachedir=/tmpfs/aicache_nightly --cs_schedule_cache --cs_cachedir
=/export/home/nitemc/cache --restart=500 'ham:detect:/home/bbmass/uploadedcorpora/jm/ham/*' --after=-15552000 --t
ail=40000 --scanprob=0.3 'spam:detect:/home/bbmass/uploadedcorpora/jm/spam/*'
**************************************************************************
*                                                                        *
*   Corpus will be run un-sorted but with date stamp loggging which is   *
*   needed for score generation log selection but is not available when  *
*   using the -n option.  This may affect the results of any bayes and   *
*   AWL tests run during this mass-check.                                *
*                                                                        *
**************************************************************************
status: starting scan stage                              now: 2008-09-12 09:21:36
............................................................
............................................................
[...etc.]
status: starting run stage                               now: 2008-09-12 09:34:53
status: server ready for connections                     now: 2008-09-12 09:34:53
status: 0 messages outstanding                           now: 2008-09-12 09:34:59
status: client 1 has 283824 msgs cached (5096 usable)    now: 2008-09-12 09:35:15
status: client 1 has 11.6% of required messages          now: 2008-09-12 09:35:15
status: POST request from 63.216.184.50                  now: 2008-09-12 09:35:15
status: 0 messages outstanding                           now: 2008-09-12 09:35:15
status: 0 messages outstanding                           now: 2008-09-12 09:36:13
status: client 2 has 302759 msgs cached (9386 usable)    now: 2008-09-12 09:36:34
status: client 2 has 21.4% of required messages          now: 2008-09-12 09:36:34
status: POST request from 192.87.106.247                 now: 2008-09-12 09:36:34
status: 0 messages outstanding                           now: 2008-09-12 09:36:34
status: 0 messages outstanding                           now: 2008-09-12 09:37:16
status: POST request from 63.216.184.50                  now: 2008-09-12 09:37:16
status: client requested 100 messages                    now: 2008-09-12 09:37:16
status: sent 100 of 100 intended messages                now: 2008-09-12 09:37:16
status: 100 messages outstanding                         now: 2008-09-12 09:37:16
status: 100 messages outstanding                         now: 2008-09-12 09:37:19

status: POST request from 63.216.184.50                  now: 2008-09-12 09:37:20
status: client requested 1000 messages                   now: 2008-09-12 09:37:20
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:37:20
status: 1000 messages outstanding                        now: 2008-09-12 09:37:20
status: 1000 messages outstanding                        now: 2008-09-12 09:37:35
status:   1% ham: 14     spam: 424    date: 2008-09-07   now: 2008-09-12 09:37:36
status:   2% ham: 26     spam: 850    date: 2008-08-29   now: 2008-09-12 09:37:36
status: POST request from 63.216.184.50                  now: 2008-09-12 09:37:36
status: client requested 1000 messages                   now: 2008-09-12 09:37:36
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:37:38
status: 1000 messages outstanding                        now: 2008-09-12 09:37:39
status: 1000 messages outstanding                        now: 2008-09-12 09:37:55
status:   3% ham: 30     spam: 1284   date: 2008-09-08   now: 2008-09-12 09:37:56
status:   4% ham: 36     spam: 1716   date: 2008-08-31   now: 2008-09-12 09:37:56
status: POST request from 63.216.184.50                  now: 2008-09-12 09:37:56
status: client requested 1000 messages                   now: 2008-09-12 09:37:56
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:38:11
status: 1000 messages outstanding                        now: 2008-09-12 09:38:13
status: 1000 messages outstanding                        now: 2008-09-12 09:38:27
status:   5% ham: 42     spam: 2148   date: 2008-08-28   now: 2008-09-12 09:38:28
status:   6% ham: 53     spam: 2575   date: 2008-08-30   now: 2008-09-12 09:38:28
status:   7% ham: 63     spam: 3003   date: 2008-08-29   now: 2008-09-12 09:38:28
status: POST request from 63.216.184.50                  now: 2008-09-12 09:38:28
status: client requested 1000 messages                   now: 2008-09-12 09:38:28
status: sent 999 of 1000 intended messages               now: 2008-09-12 09:38:40
status: 999 messages outstanding                         now: 2008-09-12 09:38:41
status: 999 messages outstanding                         now: 2008-09-12 09:38:41
status: 999 messages outstanding                         now: 2008-09-12 09:38:42
status: client 3 has 298099 msgs cached (5875 usable)    now: 2008-09-12 09:39:00
status: client 3 has 13.4% of required messages          now: 2008-09-12 09:39:00
status: POST request from 85.91.5.16                     now: 2008-09-12 09:39:00
status: 999 messages outstanding                         now: 2008-09-12 09:39:00
status: POST request from 192.87.106.247                 now: 2008-09-12 09:39:00
status: client requested 100 messages                    now: 2008-09-12 09:39:00
status: sent 100 of 100 intended messages                now: 2008-09-12 09:39:00
status: 1099 messages outstanding                        now: 2008-09-12 09:39:00
status: 1099 messages outstanding                        now: 2008-09-12 09:39:02
status: POST request from 192.87.106.247                 now: 2008-09-12 09:39:03
status: client requested 1000 messages                   now: 2008-09-12 09:39:03
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:39:03
status: 1999 messages outstanding                        now: 2008-09-12 09:39:03
status: 1999 messages outstanding                        now: 2008-09-12 09:39:19
status:   8% ham: 142    spam: 3362   date: 2008-08-28   now: 2008-09-12 09:39:20
status:   9% ham: 230    spam: 3712   date: 2008-09-02   now: 2008-09-12 09:39:20
status: POST request from 192.87.106.247                 now: 2008-09-12 09:39:20
status: client requested 1000 messages                   now: 2008-09-12 09:39:20
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:39:20
status: 1999 messages outstanding                        now: 2008-09-12 09:39:20
spf: lookup failed: Net::DNS::typesbyname() argument (SPF) is not TYPE### at /local/perl586/lib/site_perl/5.8.6/i
86pc-solaris/Net/DNS.pm line 156.
status: 1999 messages outstanding                        now: 2008-09-12 09:39:36
status:  10% ham: 304    spam: 4076   date: 2008-06-06   now: 2008-09-12 09:39:37
status:  11% ham: 390    spam: 4428   date: 2008-09-05   now: 2008-09-12 09:39:37
status: POST request from 192.87.106.247                 now: 2008-09-12 09:39:37
status: client requested 1000 messages                   now: 2008-09-12 09:39:37
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:39:37
status: 1999 messages outstanding                        now: 2008-09-12 09:39:37
status: 1999 messages outstanding                        now: 2008-09-12 09:39:54
status:  12% ham: 486    spam: 4770   date: 2008-08-25   now: 2008-09-12 09:39:55
status:  13% ham: 614    spam: 5080   date: 2008-08-26   now: 2008-09-12 09:39:55
status:  14% ham: 720    spam: 5412   date: 2008-08-29   now: 2008-09-12 09:39:55
status: POST request from 192.87.106.247                 now: 2008-09-12 09:39:55
status: client requested 1000 messages                   now: 2008-09-12 09:39:55
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:39:59
status: 1999 messages outstanding                        now: 2008-09-12 09:40:03
spf: lookup failed: Net::DNS::typesbyname() argument (SPF) is not TYPE### at /local/perl586/lib/site_perl/5.8.6/i
86pc-solaris/Net/DNS.pm line 156.
status: 1999 messages outstanding                        now: 2008-09-12 09:40:17
status:  15% ham: 774    spam: 5796   date: 2008-09-05   now: 2008-09-12 09:40:18
status:  16% ham: 835    spam: 6173   date: 2008-09-11   now: 2008-09-12 09:40:18
status: POST request from 192.87.106.247                 now: 2008-09-12 09:40:18
status: client requested 1000 messages                   now: 2008-09-12 09:40:18
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:40:26
status: 1999 messages outstanding                        now: 2008-09-12 09:40:33
status: 1999 messages outstanding                        now: 2008-09-12 09:40:46
status:  17% ham: 862    spam: 6584   date: 2008-09-09   now: 2008-09-12 09:40:47
status:  18% ham: 864    spam: 7020   date: 2008-09-09   now: 2008-09-12 09:40:47
status: POST request from 192.87.106.247                 now: 2008-09-12 09:40:47
status: client requested 1000 messages                   now: 2008-09-12 09:40:47
status: sent 998 of 1000 intended messages               now: 2008-09-12 09:40:54
status: 1997 messages outstanding                        now: 2008-09-12 09:40:58
status: 1997 messages outstanding                        now: 2008-09-12 09:41:00
status: POST request from 85.91.5.16                     now: 2008-09-12 09:41:01
status: client requested 100 messages                    now: 2008-09-12 09:41:01
status: sent 100 of 100 intended messages                now: 2008-09-12 09:41:01
status: 2097 messages outstanding                        now: 2008-09-12 09:41:01
spf: lookup failed: Net::DNS::typesbyname() argument (SPF) is not TYPE### at /local/perl586/lib/site_perl/5.8.6/i
86pc-solaris/Net/DNS.pm line 156.
status: 2097 messages outstanding                        now: 2008-09-12 09:41:09
status: POST request from 85.91.5.16                     now: 2008-09-12 09:41:10
status: client requested 1000 messages                   now: 2008-09-12 09:41:10
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:41:10
status: 2997 messages outstanding                        now: 2008-09-12 09:41:10
status: 2997 messages outstanding                        now: 2008-09-12 09:41:53
status:  19% ham: 874    spam: 7448   date: 2008-09-03   now: 2008-09-12 09:41:54
status:  20% ham: 884    spam: 7876   date: 2008-09-03   now: 2008-09-12 09:41:54
status:  21% ham: 892    spam: 8306   date: 2008-08-26   now: 2008-09-12 09:41:54
status: POST request from 85.91.5.16                     now: 2008-09-12 09:41:54
status: client requested 1000 messages                   now: 2008-09-12 09:41:54
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:41:58
status: 2997 messages outstanding                        now: 2008-09-12 09:41:59
status: 2997 messages outstanding                        now: 2008-09-12 09:43:15
status:  22% ham: 899    spam: 8737   date: 2008-08-27   now: 2008-09-12 09:43:17
status:  23% ham: 905    spam: 9169   date: 2008-08-27   now: 2008-09-12 09:43:17
status: POST request from 85.91.5.16                     now: 2008-09-12 09:43:17
status: client requested 1000 messages                   now: 2008-09-12 09:43:17
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:45:41
status: 2997 messages outstanding                        now: 2008-09-12 09:45:44
status: 2997 messages outstanding                        now: 2008-09-12 09:47:47
status:  24% ham: 908    spam: 9604   date: 2008-09-05   now: 2008-09-12 09:47:48
status:  25% ham: 910    spam: 10040  date: 2008-09-11   now: 2008-09-12 09:47:48
status: POST request from 85.91.5.16                     now: 2008-09-12 09:47:48
status: client requested 991 messages                    now: 2008-09-12 09:47:48
status: sent 991 of 991 intended messages                now: 2008-09-12 09:48:10
status: 1997 messages outstanding                        now: 2008-09-12 09:48:13
status: 1997 messages outstanding                        now: 2008-09-12 09:49:59
status:  26% ham: 913    spam: 10475  date: 2008-09-01   now: 2008-09-12 09:50:01
status:  27% ham: 918    spam: 10908  date: 2008-09-08   now: 2008-09-12 09:50:01
status:  28% ham: 921    spam: 11343  date: 2008-09-10   now: 2008-09-12 09:50:01
status: POST request from 85.91.5.16                     now: 2008-09-12 09:50:01
status: client requested 1000 messages                   now: 2008-09-12 09:50:01
status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:50:10
status: 1006 messages outstanding                        now: 2008-09-12 09:50:12
status: 1006 messages outstanding                        now: 2008-09-12 09:52:15
status:  29% ham: 925    spam: 11777  date: 2008-08-29   now: 2008-09-12 09:52:16
status:  30% ham: 928    spam: 12212  date: 2008-09-06   now: 2008-09-12 09:52:16
status: POST request from 85.91.5.16                     now: 2008-09-12 09:52:16
status: client requested 991 messages                    now: 2008-09-12 09:52:16
status: sent 991 of 991 intended messages                now: 2008-09-12 09:52:24
status: 991 messages outstanding                         now: 2008-09-12 09:52:26
status: 991 messages outstanding                         now: 2008-09-12 09:54:31
status:  31% ham: 930    spam: 12648  date: 2008-09-07   now: 2008-09-12 09:54:32
status:  32% ham: 935    spam: 13081  date: 2008-09-07   now: 2008-09-12 09:54:32
status: POST request from 85.91.5.16                     now: 2008-09-12 09:54:32
status: client requested 966 messages                    now: 2008-09-12 09:54:32
status: sent 965 of 966 intended messages                now: 2008-09-12 09:54:38
status: 965 messages outstanding                         now: 2008-09-12 09:54:41
Killed by signal 15.
Killed by signal 15.
Killed by signal 15.
/export/home/nitemc/jm/svn/masses/rule-qa/corpus-nightly.post-svn: line 83: 25071 Terminated              $PERL m
ass-check --noisy --progress --cs_ssl --server $serverhost --run_post_scan="./rule-qa/nightly-slaves-start $clien
thosts" $opts


[the "kills" take place the next morning; so it hangs each night for ~23 hours.]

--j.

Re: distributed mass-checks hanging again

Posted by "Daryl C. W. O'Shea" <sp...@dostech.ca>.
On 13/09/2008 6:09 AM, Justin Mason wrote:
> status: POST request from 63.216.184.50                  now: 2008-09-12 09:38:28
> status: client requested 1000 messages                   now: 2008-09-12 09:38:28
> status: sent 999 of 1000 intended messages               now: 2008-09-12 09:38:40

> status: POST request from 192.87.106.247                 now: 2008-09-12 09:39:20
> status: client requested 1000 messages                   now: 2008-09-12 09:39:20
> status: sent 1000 of 1000 intended messages              now: 2008-09-12 09:39:20
> status: 1999 messages outstanding                        now: 2008-09-12 09:39:20
> spf: lookup failed: Net::DNS::typesbyname() argument (SPF) is not TYPE### at /local/perl586/lib/site_perl/5.8.6/i
> 86pc-solaris/Net/DNS.pm line 156.
> status: 1999 messages outstanding                        now: 2008-09-12 09:39:36

> status: POST request from 192.87.106.247                 now: 2008-09-12 09:40:47
> status: client requested 1000 messages                   now: 2008-09-12 09:40:47
> status: sent 998 of 1000 intended messages               now: 2008-09-12 09:40:54

> status: POST request from 85.91.5.16                     now: 2008-09-12 09:54:32
> status: client requested 966 messages                    now: 2008-09-12 09:54:32
> status: sent 965 of 966 intended messages                now: 2008-09-12 09:54:38
> status: 965 messages outstanding                         now: 2008-09-12 09:54:41
> Killed by signal 15.
> Killed by signal 15.
> Killed by signal 15.

Each of the slaves are hanging up after the server can't find all of the
messages it had intended to send.  I'm not sure why this is causing a
problem though as it was fixed long ago by sending a generated empty
message that the client could scan instead.

It also looks like there's an issue with Perl, or at least Net::DNS, on
the new Solaris zone.

Daryl