The __internal_delivery_user__ doesn't have an inbox. That should not be
a problem, but apparently it can be.
You are delivering the *very* first message to your new installation
through LMTP it seems, which triggers a previously unknown(?) bug.
Try inserting at least one single message into your system (to any user,
even an invalid one will do) through dbmail-smtp.
Patrick de Ruiter wrote:
> Hi Guys,
>
>
>
> I’m trying to setup DBMail 2.2.8 on Solaris 10 u4 (sparc) with postfix
> 2.4.6 and mysql 5.0.37 (with InnoDB tables)
>
>
>
> Everything is configured as described in the documentation but DBMail
> doesn’t accept the email, it says “no mailbox found”, however when I
> telnet to the pop3 daemon I can login normally with that user account
> but the mailbox stays empty. The strange thing is that it can actually
> find the alias in the database and also the id of the corresponding user.
>
>
>
> Any help to resolve this (probably minor) issue is greatly appreciated
>
>
>
> Postfix shows the following error:
>
> jan 30 14:58:22 smtp2 postfix/lmtp[10581]: [ID 197553 mail.info]
> 379DE7827: to=<[EMAIL PROTECTED]>, relay=127.0.0.1[127.0.0.1]:24,
> delay=12658, delays=12658/0.04/0.04/0.04, dsn=4.4.2, status=deferred
> (lost connection with 127.0.0.1[127.0.0.1] while sending end of data --
> message may be sent more than once)
>
>
>
>
>
> This is some output from the log file dbmail.err:
>
> Jan 30 14:58:22 smtp2 [10561]: Info:[serverchild]
> serverchild.c,select_and_accept(+282): connection accepted
>
> Jan 30 14:58:22 smtp2 [10561]: Message:[serverchild]
> serverchild.c,PerformChildTask(+349): incoming connection from
> [127.0.0.1] by pid [10561]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[serverchild]
> serverchild.c,PerformChildTask(+374): client info init complete, calling
> client handler
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+270): incoming
> buffer: [LHLO smtp2.example.com]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+284): command
> issued :cmd [LHLO], value [smtp2.example.com]
>
>
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+292): command
> looked up as commandtype 0
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+270): incoming
> buffer: [MAIL FROM:<[EMAIL PROTECTED]>]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+284): command
> issued :cmd [MAIL], value [FROM:<[EMAIL PROTECTED]>]
>
>
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+292): command
> looked up as commandtype 4
>
> Jan 30 14:58:22 smtp2 [10561]: Info:[misc] misc.c,find_bounded(+381):
> Found [EMAIL PROTECTED] of length [22] between '<' and '>' so next
> skip [28]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+270): incoming
> buffer: [RCPT TO:<[EMAIL PROTECTED]>]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+284): command
> issued :cmd [RCPT], value [TO:<[EMAIL PROTECTED]>]
>
>
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+292): command
> looked up as commandtype 9
>
> Jan 30 14:58:22 smtp2 [10561]: Info:[misc] misc.c,find_bounded(+381):
> Found [EMAIL PROTECTED] of length [22] between '<' and '>' so next
> skip [26]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[dsn] dsn.c,dsnuser_init(+202):
> dsnuser initialized
>
> Jan 30 14:58:22 smtp2 [10561]: Info:[dsn] dsn.c,dsnuser_resolve(+578):
> checking if [EMAIL PROTECTED] is a valid username, alias, or catchall.
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[auth]
> authsql.c,auth_check_user_ext(+222): checking user
> [EMAIL PROTECTED] in alias table
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[auth]
> authsql.c,auth_check_user_ext(+239): checks [0]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[sql] dbmysql.c,db_query(+287):
> query [SELECT deliver_to FROM dbmail_aliases WHERE lower(alias) =
> lower('[EMAIL PROTECTED]') AND lower(alias) <> lower(deliver_to)]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db] dbmodule.c,db_query(+145):
> last query took [0] seconds
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[auth]
> authsql.c,auth_check_user_ext(+273): into checking loop
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[auth]
> authsql.c,auth_check_user_ext(+279): checking user [EMAIL PROTECTED] to 4
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[auth]
> authsql.c,auth_check_user_ext(+222): checking user [4] in alias table
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[auth]
> authsql.c,auth_check_user_ext(+239): checks [1]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[sql] dbmysql.c,db_query(+287):
> query [SELECT deliver_to FROM dbmail_aliases WHERE lower(alias) =
> lower('4') AND lower(alias) <> lower(deliver_to)]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db] dbmodule.c,db_query(+145):
> last query took [0] seconds
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[auth]
> authsql.c,auth_check_user_ext(+261): adding [4] to deliver_to address
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[dsn]
> dsn.c,address_has_alias(+251): user [EMAIL PROTECTED] found total
> of [1] aliases
>
> Jan 30 14:58:22 smtp2 [10561]: Info:[dsn] dsn.c,dsnuser_resolve(+585):
> delivering [EMAIL PROTECTED] as an alias.
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+270): incoming
> buffer: [DATA]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+292): command
> looked up as commandtype 3
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+554):
> requesting sender to begin message.
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[message]
> dbmail-message.c,_set_content_from_stream(+419): parse message
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[lmtp] lmtp.c,lmtp(+585): whole
> message = Received: from example.com (localhost [127.0.0.1])
>
> by smtp2.example.com (Postfix) with ESMTP id 379DE7827
>
> for <[EMAIL PROTECTED]>; Wed, 30 Jan 2008 11:27:24 +0100 (CET)
>
> Subject:test2
>
> Message-Id: <[EMAIL PROTECTED]>
>
> Date: Wed, 30 Jan 2008 11:27:24 +0100 (CET)
>
> From: [EMAIL PROTECTED]
>
> To: undisclosed-recipients:;
>
>
>
> test2
>
>
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[sql] dbmysql.c,db_query(+287):
> query [BEGIN]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db] dbmodule.c,db_query(+145):
> last query took [0] seconds
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[sql] dbmysql.c,db_query(+287):
> query [SELECT user_idnr FROM dbmail_users WHERE lower(userid) =
> lower('[EMAIL PROTECTED]@__')]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db] dbmodule.c,db_query(+145):
> last query took [0] seconds
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[misc]
> misc.c,create_unique_id(+113): created: 9dd352d7163069d53988430436c47730
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db] db.c,db_findmailbox(+2596):
> looking for mailbox with FQN [INBOX].
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[sql] dbmysql.c,db_query(+287):
> query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE name LIKE 'INBOX'
> AND owner_idnr=1]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db] dbmodule.c,db_query(+145):
> last query took [0] seconds
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db]
> db.c,db_findmailbox_owner(+2730): no mailbox found
>
> Jan 30 14:58:22 smtp2 [10561]: Info:[db]
> db.c,db_mailbox_create_with_parents(+3213): Creating mailbox [INBOX]
> source [6] for user [1]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db] db.c,db_findmailbox(+2596):
> looking for mailbox with FQN [INBOX].
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[sql] dbmysql.c,db_query(+287):
> query [SELECT mailbox_idnr FROM dbmail_mailboxes WHERE name LIKE 'INBOX'
> AND owner_idnr=1]
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db] dbmodule.c,db_query(+145):
> last query took [0] seconds
>
> Jan 30 14:58:22 smtp2 [10561]: Debug:[db]
> db.c,db_findmailbox_owner(+2730): no mailbox found
>
> Jan 30 14:58:22 smtp2 [10583]: Message:[server]
> pool.c,child_register(+299): register child [10583]
>
> Jan 30 14:58:22 smtp2 [10583]: Info:[server]
> pool.c,child_register(+324): initializing child_state [10583] using slot [1]
>
> Jan 30 14:58:22 smtp2 [10583]: Info:[serverchild]
> serverchild.c,SetChildSigHandler(+152): signal handler placed
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[db]
> dbmodule.c,db_load_driver(+56): library_directory is
> [/opt/dbmail/lib/dbmail]
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[db]
> dbmodule.c,db_load_driver(+69): looking for mysql as
> /opt/dbmail/lib/dbmail/libmysql.so
>
> Jan 30 14:58:22 smtp2 [10500]: Message:[server]
> pool.c,scoreboard_state(+590): Scoreboard state: children [2/10], spares
> [2 (2 - 4)]
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[sql] dbmysql.c,db_query(+287):
> query [SET NAMES latin1]
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[db] dbmodule.c,db_query(+145):
> last query took [0] seconds
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[sql] dbmysql.c,db_query(+287):
> query [SHOW VARIABLES LIKE 'collation_%']
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[db] dbmodule.c,db_query(+145):
> last query took [0] seconds
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[sql]
> dbmysql.c,db_mysql_check_collations(+121): does
> [collation_database:latin1_swedish_ci] match
> [collation_connection:latin1_swedish_ci]?
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[auth]
> authmodule.c,auth_load_driver(+51): library_directory is
> [/opt/dbmail/lib/dbmail]
>
> Jan 30 14:58:22 smtp2 [10583]: Debug:[auth]
> authmodule.c,auth_load_driver(+64): looking for auth_sql as
> /opt/dbmail/lib/dbmail/libauth_sql.so
>
>
>
> Regards,
>
> Patrick
>
>
>
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> DBmail mailing list
> [email protected]
> https://mailman.fastxs.nl/mailman/listinfo/dbmail
--
________________________________________________________________
Paul Stevens paul at nfg.nl
NET FACILITIES GROUP GPG/PGP: 1024D/11F8CD31
The Netherlands________________________________http://www.nfg.nl
_______________________________________________
DBmail mailing list
[email protected]
https://mailman.fastxs.nl/mailman/listinfo/dbmail
