A NOTE has been added to this issue. ====================================================================== http://www.dbmail.org/mantis/view.php?id=475 ====================================================================== Reported By: lrosenman Assigned To: ====================================================================== Project: DBMail Issue ID: 475 Category: Database layer Reproducibility: always Severity: major Priority: normal Status: new target: ====================================================================== Date Submitted: 14-Dec-06 23:56 CET Last Modified: 16-Dec-06 20:21 CET ====================================================================== Summary: Invalid timestamps generated to PostgreSQL backend Description: Random messages coming in via dbmail-smtp are failed going into a PostgreSQL 8.1.5 (SQL_ASCII) Database.
====================================================================== ---------------------------------------------------------------------- lrosenman - 14-Dec-06 23:59 ---------------------------------------------------------------------- Here's the DB log for the same message (First one): $ grep 'pg-prod\[38071\]' /var/log/pg-prod.log Dec 14 15:42:45 thebighonker pg-prod[38071]: [1-1] <[unknown]%[unknown]> LOG: connection received: host=localhost port=63419 Dec 14 15:42:45 thebighonker pg-prod[38071]: [2-1] <ler%dbmail> LOG: connection authorized: user=ler database=dbmail Dec 14 15:42:45 thebighonker pg-prod[38071]: [3-1] <ler%dbmail> LOG: statement: SELECT 1=1 FROM dbmail_physmessage LIMIT 1 OFFSET 0 Dec 14 15:42:45 thebighonker pg-prod[38071]: [4-1] <ler%dbmail> LOG: duration: 6.107 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [5-1] <ler%dbmail> LOG: statement: SELECT 1=1 FROM dbmail_headervalue LIMIT 1 OFFSET 0 Dec 14 15:42:45 thebighonker pg-prod[38071]: [6-1] <ler%dbmail> LOG: duration: 1.287 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [7-1] <ler%dbmail> LOG: statement: SELECT 1=1 FROM dbmail_envelope LIMIT 1 OFFSET 0 Dec 14 15:42:45 thebighonker pg-prod[38071]: [8-1] <ler%dbmail> LOG: duration: 1.443 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [9-1] <ler%dbmail> LOG: statement: SELECT deliver_to FROM dbmail_aliases WHERE lower(alias) = lower('ler') AND lower(alias) <> Dec 14 15:42:45 thebighonker pg-prod[38071]: [9-2] lower(deliver_to) Dec 14 15:42:45 thebighonker pg-prod[38071]: [10-1] <ler%dbmail> LOG: duration: 2.517 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [11-1] <ler%dbmail> LOG: statement: SELECT user_idnr FROM dbmail_users WHERE lower(userid) = lower('ler') Dec 14 15:42:45 thebighonker pg-prod[38071]: [12-1] <ler%dbmail> LOG: duration: 1.482 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [13-1] <ler%dbmail> LOG: statement: BEGIN Dec 14 15:42:45 thebighonker pg-prod[38071]: [14-1] <ler%dbmail> LOG: duration: 0.258 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [15-1] <ler%dbmail> LOG: statement: SELECT user_idnr FROM dbmail_users WHERE lower(userid) = lower('[EMAIL PROTECTED]@__') Dec 14 15:42:45 thebighonker pg-prod[38071]: [16-1] <ler%dbmail> LOG: duration: 0.565 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [17-1] <ler%dbmail> LOG: statement: SELECT mailbox_idnr FROM dbmail_mailboxes WHERE name ILIKE 'INBOX' AND owner_idnr=1 Dec 14 15:42:45 thebighonker pg-prod[38071]: [18-1] <ler%dbmail> LOG: duration: 1.737 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [19-1] <ler%dbmail> LOG: statement: INSERT INTO dbmail_physmessage (messagesize, internal_date) VALUES (0, Dec 14 15:42:45 thebighonker pg-prod[38071]: [19-2] TO_TIMESTAMP('1166132546-05-07 15:42:45', 'YYYY-MM-DD HH:MI:SS')) Dec 14 15:42:45 thebighonker pg-prod[38071]: [20-1] <ler%dbmail> ERROR: timestamp out of range Dec 14 15:42:45 thebighonker pg-prod[38071]: [20-2] <ler%dbmail> STATEMENT: INSERT INTO dbmail_physmessage (messagesize, internal_date) VALUES (0, TO_TIMESTAMP('1166132546-05-07 Dec 14 15:42:45 thebighonker pg-prod[38071]: [20-3] 15:42:45', 'YYYY-MM-DD HH:MI:SS')) Dec 14 15:42:45 thebighonker pg-prod[38071]: [21-1] <ler%dbmail> LOG: statement: ROLLBACK Dec 14 15:42:45 thebighonker pg-prod[38071]: [22-1] <ler%dbmail> LOG: duration: 0.174 ms Dec 14 15:42:45 thebighonker pg-prod[38071]: [23-1] <ler%dbmail> LOG: disconnection: session time: 0:00:00.03 user=ler database=dbmail host=localhost port=63419 $ I may be able to get the message from my MBX store if y'all feel it's necessary. Thanks! ---------------------------------------------------------------------- lrosenman - 15-Dec-06 17:26 ---------------------------------------------------------------------- I just attached a copy of the message that caused this, as it exists in my MBX file (the first line is the MBX header for it, IIRC). ---------------------------------------------------------------------- lrosenman - 15-Dec-06 17:28 ---------------------------------------------------------------------- gmime version is 2.2.3. Platform, more specifically, is FreeBSD/amd64 6.2-PRERELEASE. the kernel/userland is from a day or 2 ago. It is running in 64-bit mode. ---------------------------------------------------------------------- lrosenman - 15-Dec-06 17:39 ---------------------------------------------------------------------- I can give shell access to the machine if that would be helpful, btw. ---------------------------------------------------------------------- aaron - 15-Dec-06 17:50 ---------------------------------------------------------------------- I have an AMD64 Xen box. I'll try to fire up a FreeBSD guest image today and see what happens. ---------------------------------------------------------------------- lrosenman - 15-Dec-06 18:32 ---------------------------------------------------------------------- Aaron, While you are looking at this one, I saw a bunch of warnings out of the code that might be worth looking at (wrong format's, etc). I used the DBMail from ports, and it installed the gmime, etc. ---------------------------------------------------------------------- aaron - 15-Dec-06 19:17 ---------------------------------------------------------------------- Please compile the timestring.c file I've uploaded and post the output. Should be as simple as 'gcc -Wall timestring.c -o timestring' and then './timestring' Let me know if you have any complications. ---------------------------------------------------------------------- lrosenman - 15-Dec-06 19:32 ---------------------------------------------------------------------- $ gcc -Wall timestring.c -o timestring timestring.c: In function `create_current_timestring': timestring.c:20: warning: statement with no effect $ ./timestring 2006-12-15 12:32:21 $ ---------------------------------------------------------------------- aaron - 15-Dec-06 19:52 ---------------------------------------------------------------------- Ok, let's try this one. ---------------------------------------------------------------------- lrosenman - 15-Dec-06 19:57 ---------------------------------------------------------------------- $ gcc -Wall -o timestring2 timestring2.c timestring2.c: In function `create_current_timestring': timestring2.c:35: warning: statement with no effect $ ./timestring2 2006-12-15 12:57:23 TO_TIMESTAMP('2006-12-15 12:57:23', 'YYYY-MM-DD HH:MI:SS') $ ---------------------------------------------------------------------- lrosenman - 16-Dec-06 18:30 ---------------------------------------------------------------------- Ok, I've found 2 things. 1) gmime 2.2.3 has a stray printf that causes exim to return the output: --- gmime-utils.c.orig Fri Jun 16 10:56:15 2006 +++ gmime-utils.c Sat Dec 16 10:25:26 2006 @@ -646,7 +646,7 @@ goto next; } else if (!tm.tm_year) { if ((n = get_year (token->start, token->len)) != -1) { - printf ("2-digit year; "); + d(printf ("2-digit year; ")); tm.tm_year = n - 1900; } goto next; 2) Yahoo headers seem to trigger the timestamp issue. attached are the 2 queue file pieces of a message that RELIABLY create the PGSQL timestamp issue. I've attached a tarball with the queue files. What else do y'all need? Thanks a ton for looking into it. LER ---------------------------------------------------------------------- aaron - 16-Dec-06 20:21 ---------------------------------------------------------------------- I emailed this bug to Jeff Stedfast, GMime maintainer. Issue History Date Modified Username Field Change ====================================================================== 14-Dec-06 23:56 lrosenman New Issue 14-Dec-06 23:59 lrosenman Note Added: 0001678 15-Dec-06 17:25 lrosenman File Added: bad.msg 15-Dec-06 17:26 lrosenman Note Added: 0001679 15-Dec-06 17:28 lrosenman Note Added: 0001680 15-Dec-06 17:39 lrosenman Note Added: 0001681 15-Dec-06 17:50 aaron Note Added: 0001682 15-Dec-06 18:32 lrosenman Note Added: 0001684 15-Dec-06 19:15 aaron File Added: timestring.c 15-Dec-06 19:17 aaron Note Added: 0001685 15-Dec-06 19:32 lrosenman Note Added: 0001686 15-Dec-06 19:51 aaron File Added: timestring2.c 15-Dec-06 19:52 aaron Note Added: 0001687 15-Dec-06 19:57 lrosenman Note Added: 0001688 16-Dec-06 18:29 lrosenman File Added: bad.msg.spool.tar.gz 16-Dec-06 18:30 lrosenman Note Added: 0001692 16-Dec-06 20:21 aaron Note Added: 0001695 ====================================================================== _______________________________________________ Dbmail-dev mailing list Dbmail-dev@dbmail.org http://twister.fastxs.net/mailman/listinfo/dbmail-dev