Found nn messages in the processing-messages database

[Mark Sapiro]

Julian Field wrote:

>If "MailScanner --processing=1" produces no output, then the records in 
>the database cannot have a count of 1 (the 2nd number in each column in 
>your table of 26 database entries below). So when you do that, the only 
>records in there must have a value of 0, which means they should have 
>been removed.


That's not what I'm seeing. Here's an unedited terminal session:

[root at sbh16 .software]# sqlite3
/var/spool/MailScanner/incoming/Processing.db
SQLite version 3.3.6
Enter ".help" for instructions
sqlite> .tables
archive     processing
sqlite> select * from archive;
sqlite> select * from processing;
67650690405.93175|1|1239641743
92295690444.31465|1|1239641635
41537690424.26867|1|1239647420
02842690389.04452|1|1239648522
57067690409.E4302|1|1239648722
16020690433.44254|1|1239648562
17300690390.3E804|1|1239671344
39224690405.41276|1|1239671354
49358690409.95149|1|1239671419
99351690429.04632|1|1239678343
88257690407.10923|1|1239681381
39387690388.E1611|1|1239686821
41693690392.32976|1|1239705347
49903690394.76309|1|1239705280
77828690380.26107|1|1239721588
95835690388.E2978|1|1239721567
00524690436.5E971|1|1239729939
06766690387.55E20|1|1239744929
06950690412.30E45|1|1239744996
87926690445.21751|1|1239747646
35592690431.581E1|1|1239747533
00894690425.97190|1|1239747558
42214690429.67487|1|1239761289
23751690385.34301|1|1239812982
97480690403.80930|1|1239906903
34979690423.56858|1|1239906907
89182690409.01989|1|1239961220
84250690369.89777|1|1239971414
38479690188.83466|1|1239971213
95234690415.83417|1|1239971390
53010690431.69741|1|1239971215
94955690401.349E4|1|1239984106
07756690452.6E220|1|1239984011
66147690469.42376|1|1239995322
68981690507.74158|1|1239995261
65431690408.11855|1|1239995452
45558690470.40965|1|1239995427
64862690404.61045|1|1239995847
94893690446.17364|1|1239995778
27233690465.E9522|1|1239995804
61750690410.E1479|1|1239997293
77095690415.72600|1|1239997286
47926690443.39474|1|1239997474
12450690471.4E939|1|1239997440
sqlite> .exit
[root at sbh16 .software]# MailScanner --processing=1
[root at sbh16 .software]# MailScanner --processing=0
Currently being processed:

Number of messages: 44
Tries   Message Next Try At
=====   ======= ===========
1       47926690443.39474       Fri Apr 17 12:44:34 2009
1       12450690471.4E939       Fri Apr 17 12:44:00 2009
1       61750690410.E1479       Fri Apr 17 12:41:33 2009
1       77095690415.72600       Fri Apr 17 12:41:26 2009
1       64862690404.61045       Fri Apr 17 12:17:27 2009
1       27233690465.E9522       Fri Apr 17 12:16:44 2009
1       94893690446.17364       Fri Apr 17 12:16:18 2009
1       65431690408.11855       Fri Apr 17 12:10:52 2009
1       45558690470.40965       Fri Apr 17 12:10:27 2009
1       66147690469.42376       Fri Apr 17 12:08:42 2009
1       68981690507.74158       Fri Apr 17 12:07:41 2009
1       94955690401.349E4       Fri Apr 17 09:01:46 2009
1       07756690452.6E220       Fri Apr 17 09:00:11 2009
1       84250690369.89777       Fri Apr 17 05:30:14 2009
1       95234690415.83417       Fri Apr 17 05:29:50 2009
1       53010690431.69741       Fri Apr 17 05:26:55 2009
1       38479690188.83466       Fri Apr 17 05:26:53 2009
1       89182690409.01989       Fri Apr 17 02:40:20 2009
1       34979690423.56858       Thu Apr 16 11:35:07 2009
1       97480690403.80930       Thu Apr 16 11:35:03 2009
1       23751690385.34301       Wed Apr 15 09:29:42 2009
1       42214690429.67487       Tue Apr 14 19:08:09 2009
1       87926690445.21751       Tue Apr 14 15:20:46 2009
1       00894690425.97190       Tue Apr 14 15:19:18 2009
1       35592690431.581E1       Tue Apr 14 15:18:53 2009
1       06950690412.30E45       Tue Apr 14 14:36:36 2009
1       06766690387.55E20       Tue Apr 14 14:35:29 2009
1       00524690436.5E971       Tue Apr 14 10:25:39 2009
1       77828690380.26107       Tue Apr 14 08:06:28 2009
1       95835690388.E2978       Tue Apr 14 08:06:07 2009
1       41693690392.32976       Tue Apr 14 03:35:47 2009
1       49903690394.76309       Tue Apr 14 03:34:40 2009
1       39387690388.E1611       Mon Apr 13 22:27:01 2009
1       88257690407.10923       Mon Apr 13 20:56:21 2009
1       99351690429.04632       Mon Apr 13 20:05:43 2009
1       49358690409.95149       Mon Apr 13 18:10:19 2009
1       39224690405.41276       Mon Apr 13 18:09:14 2009
1       17300690390.3E804       Mon Apr 13 18:09:04 2009
1       57067690409.E4302       Mon Apr 13 11:52:02 2009
1       16020690433.44254       Mon Apr 13 11:49:22 2009
1       02842690389.04452       Mon Apr 13 11:48:42 2009
1       41537690424.26867       Mon Apr 13 11:30:20 2009
1       67650690405.93175       Mon Apr 13 09:55:43 2009
1       92295690444.31465       Mon Apr 13 09:53:55 2009
[root at sbh16 .software]#


>I cannot find any situation where the records would fail to be deleted, 
>if it says it has deleted them. The only way that can happen is if the 
>message id was blank, and all the records in your "processing" database 
>table you included below all have non-blank message ids, so it isn't that.
>
>The code for clearing out the database table is pretty straightforward, 
>please take a look at it yourself and see if you agree with me. It 
>starts at "sub ClearOutProcessedDatabase {" in 
>/usr/lib/MailScanner/MailScanner/MessageBatch.pm. If you can see any 
>bugs or holes in there, please do tell me!

I've looked at the code and I agree provided that there are no
duplicate  ids. However, I note that this problem started when I
upgraded from 4.76.7 to 4.76.10 which also upgraded DBM::SQLite from
1.13 to 1.21.

Is it possible that something in this SQLite upgrade, possibly in
combination with something in MailScanner/MailScanner/Postfix.pm is
putting duplicates into the database?

-- 
Mark Sapiro <mark at msapiro.net>        The highway is for gamblers,
San Francisco Bay Area, California    better use your sense - B. Dylan