Dotaz: Přihlášení k mailu selže, v logu je vše OK (ubuntu 12.04 + postfix + dovecot)

[Jarda]

Dobrý den, chtěl bych se poradit jedním problémem. Snažím se připojit na svůj server ale nejde to, když to skouším například přes thunderbird tak se mi vypíše:

Server pokus@xxxx.cz byl odpojen. Buď nefunguje server nebo je problém v síťovám spojení.

Když se podívám do logu na server tak tam vypadá jako by se uživatel normálně připojil, žádná chyba tam není.

Aug 10 20:30:04 imap-login: Info: Login: user=pokus@xxxx.cx method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1637, secured

Nenapadá někoho kde by mohla být chyba?

Používám Ubuntu 12.04 + postfix + dovecot, uzivatele overuji v soubor /etc/dovecot/users

Odpovědi

[ZAH]

Co vypíše

netstat | dovecot

[Jarda]

V první řadě díky za reakci. Sice vůbec nevím k čemu to je, ale vypíše to toto:

Fatal: Dovecot is already running with PID 886 (read from /var/run/dovecot/master.pid)

[Jendа]

netstat |grep dovecot

když už…

Tipuji, že tam poslouchá. Podívat bych se na to Wiresharkem nebo tcpdumpem.

[Jarda]

unix  3      [ ]         STREAM     CONNECTED     33207    /var/run/dovecot/anvil-auth-penalty

Stejně furt nevim k čemu to je dobrý

[Krystl]

Ja mel podobny problem s courier-imap, prihlaseni v pohode, ale pak se imap zasekl a po chvili spadl. V logu vypadalo vsechno v poradku. Po rebootu vse chvili fungovalo a pak zas prestalo. Bylo to programem gam_server. Kdyz jsem ho ukoncil, tak to zas na chvili fungovalo. Nakonec to skoncilo pravidelnym zabijenim gam_serveru v cronu.

[Jarda]

No já mám pravě taky pocit, že mi to šlapalo a pak to začalo najedno zlobit, takže bych klidně taky podezříval nějaký prográmek, jak jsi zjistil co to dělá? Dík

[linuxik]

Ahoj,

zkus se pripojit na IMAP server telnetem. Uvidis jakou chybu dostane klient od Dovecotu a s tim jiz neco vymyslis a ne bo zapni debug(auth_verbose=yes, auth_debug=yes, mail_debug=yes, auth_debug_passwords=yes) v Dovecotu. Takhle je to hadani z kristalove koule.

[Jarda]

Ahoj, vše jsem zapnul, tady je vysledek:

Aug 11 12:12:45 auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Aug 11 12:12:45 auth: Debug: passwd-file /etc/dovecot/users: Read 1 users
Aug 11 12:12:45 auth: Debug: auth client connected (pid=7069)
Aug 11 12:12:45 imap-login: Info: Aborted login (no auth attempts): rip=109.80.219.103, lip=192.168.0.100, TLS
Aug 11 12:12:46 auth: Debug: auth client connected (pid=7073)
Aug 11 12:12:46 auth: Debug: client in: AUTH    1       PLAIN   service=imap    secured lip=192.168.0.100       rip=109.80.219.103      lport=143       rport=26010
Aug 11 12:12:46 auth: Debug: client out: CONT   1
Aug 11 12:12:46 auth: Debug: client in: CONT    1       AHBva3VzAGhlc2xv
Aug 11 12:12:46 auth: Debug: passwd-file(pokus,109.80.219.103): lookup: user=pokus file=/etc/dovecot/users
Aug 11 12:12:46 auth: Debug: client out: OK     1       user=pokus
Aug 11 12:12:46 auth: Debug: master in: REQUEST 3148873729      7073    1       91b446d774ea07d06b13f50a6be43c5e
Aug 11 12:12:46 auth: Debug: passwd-file(pokus,109.80.219.103): lookup: user=pokus file=/etc/dovecot/users
Aug 11 12:12:46 auth: Debug: master out: USER   3148873729      pokus   uid=200 gid=200 home=/var/www/xxx.cz/mails        mail=maildir:~/pokus
Aug 11 12:12:46 imap-login: Info: Login: user=pokus, method=PLAIN, rip=109.80.219.103, lip=192.168.0.100, mpid=7074, TLS
Aug 11 12:12:46 imap: Debug: Added userdb setting: mail=maildir:~/pokus
Aug 11 12:12:46 imap(pokus): Debug: Effective uid=200, gid=200, home=/var/www/xxxx.cz/mails
Aug 11 12:12:46 imap(pokus): Debug: maildir++: root=/var/www/xxxx.cz/mails/pokus, index=, control=, inbox=/var/www/xxxx.cz/mails/pokus, alt=
Aug 11 12:12:46 auth: Debug: auth client connected (pid=7075)
Aug 11 12:12:46 imap-login: Info: Aborted login (no auth attempts): rip=109.80.219.103, lip=192.168.0.100, TLS
Aug 11 12:12:46 auth: Debug: auth client connected (pid=7076)
Aug 11 12:12:46 auth: Debug: client in: AUTH    1       PLAIN   service=imap    secured lip=192.168.0.100       rip=109.80.219.103      lport=143       rport=26012
Aug 11 12:12:46 auth: Debug: client out: CONT   1
Aug 11 12:12:46 auth: Debug: client in: CONT    1       AHBva3VzAGhlc2xv
Aug 11 12:12:46 auth: Debug: passwd-file(pokus,109.80.219.103): lookup: user=pokus file=/etc/dovecot/users
Aug 11 12:12:46 auth: Debug: client out: OK     1       user=pokus
Aug 11 12:12:46 auth: Debug: master in: REQUEST 1219362817      7076    1       d72fd4838f652538c88726bf3b0b7137
Aug 11 12:12:46 auth: Debug: passwd-file(pokus,109.80.219.103): lookup: user=pokus file=/etc/dovecot/users
Aug 11 12:12:46 auth: Debug: master out: USER   1219362817      pokus   uid=200 gid=200 home=/var/www/xxxx.cz/mails        mail=maildir:~/pokus
Aug 11 12:12:46 imap-login: Info: Login: user=pokus, method=PLAIN, rip=109.80.219.103, lip=192.168.0.100, mpid=7077, TLS
Aug 11 12:12:46 imap: Debug: Added userdb setting: mail=maildir:~/pokus
Aug 11 12:12:46 imap(pokus): Debug: Effective uid=200, gid=200, home=/var/www/xxxx.cz/mails
Aug 11 12:12:46 imap(pokus): Debug: maildir++: root=/var/www/xxxx.cz/mails/pokus, index=, control=, inbox=/var/www/xxxx.cz/mails/pokus, alt=

Moc z toho teda chytřejší nejsem... Jdu zkusit ten telnet...

[linuxik]

Jedine co v tom vidim je "imap-login: Info: Aborted login (no auth attempts)" , zkus v thunderbirdu vypnout TLS nech to normalne na PLAIN.

[Jarda]

A tady je ten telnet:

$ telnet imap.xxxx.cz imap
Trying xx.xx.xxx.xxx...
Connected to imap.xxxx.cz.
Escape character is '^]'.
* OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN] Dovecot ready.
01 LOGIN pokus heslo
* BYE Internal error occurred. Refer to server log for more information.
Connection closed by foreign host.

V logu samozřejmě vše ok, tedy v dovecot logu a v mail logu, ale asi v jiném to nenajduu že...

[linuxik]

Zahada , jsou dobre prava k adresari /var/www/xxxx.cz/mails ?

[Jarda]

uzivalte vmail(200), skupina vmail(200) a prava 777. Ale díky za nakopnutí, ted koukám, že ačkoliv je to tak jak říkám. tak když si pošlu mail např z venku tak v logu postfixu je toto:

Aug 11 08:31:39 mail2 postfix/virtual[5344]: warning: maildir access problem for UID/GID=200/200: create maildir file /var/www/mails/pokus/tmp/1344666699.P5344.mail2: Permission denied
Aug 11 08:31:39 mail2 postfix/virtual[5344]: warning: perhaps you need to create the maildirs in advance
Aug 11 08:31:39 mail2 postfix/virtual[5344]: 3D1427C0080: to=pokus@xxxx.cz, relay=virtual, delay=38226, delays=38226/0.01/0/0.1, dsn=4.2.0, status=deferred (maildir delivery failed: create maildir file /var/www/mails/pokus/tmp/1344666699.P5344.mail2: Permission denied)

Pro jistotu jsem ještě vytvořil složku tmp a dal jí také 200.200 (ačkoliv jsem si jist že tu by si měl postfix vytvořit sám). Výsledek je však stejný. Tak já už jsem asi opravdu blázen... jsem si na 100% jistý že je /var/www/mails/pokus uivatele 200 skupiny 200 a že má 777 a přesto to hlásí problém s právy.

[linuxik]

Nebezi postfix v chrootu?

[Jarda]

Zdá se že ano, tedy pokud to určuje toto v master.cf:

# ==========================================================================
smtp      inet  n       -       -       -       -       smtpd

To je problém?

[linuxik]

Urcite, protoze potom svuj root(/) adresar ma nekde ve /var/spoo/postfix, takze adresar ve /var/www/ pro nej vubec neexistuje.

[Jarda]

Jenže kde? Jak to zjistím? Je mi to ale stejně divné, nastavení postfixu jsem neměnil, a ještě před dvouma dnama to fungovalo. Doinstaloval jsem pár věcí, tak jsem měl pocit že to dělá nějaký program. Na mailovou část jsem vůbec nesahal...

[linuxik]

Aha, tak jestli to fungovalo, mohlo by to byt nejakym security nastavenim. V Centosu je to SELINUX. V Ubuntu nevim, ale urcite neco podobneho ma.

[Jarda]

Něco takového to asi bude, na mastar.cf jsem na 100% nesahal. Ted jsem se koukal jak to je v defaultu (ihned po instalaci) a je to přesně tak jak to ted mám já a to určitě fungovalo. Doinstaloval jsem postgreSQL, phppgadmin, git, phpmyadmin, gitweb, a možná ještě něco. Něco z toho musel změnit nějaké tohle nastavení, ted zjistit co...

[vasek]

V ubuntu jsou některý balíčky pěkný mrchy a po aktualizaci změní oprávnění některých souborů. Ale myslím, že tady by to mohl být problém s apparmor (/etc/apparmor.d/) oprávněními.

[Jarda]

Děkuji všem za rady, ale bohužel to opět nepomohlo. Odstranil jsem apparmor, selinux v základu ubuntu není, ale pro jistotu jsem to zkontroloval a opravdu tam není. Restartoval jsem server, poslal email a znovu to same:

Aug 11 17:04:03 mail2 postfix/virtual[1646]: warning: maildir access problem for UID/GID=200/200: create maildir file /var/www/xxxx.cz/mails/pokus/tmp/1344697443.P1646.mail2: Permission denied

Má snad ještě někdo nápad čím by to mohlo být?

[Jarda]

Tak pozor, všechno zpět, blbě jsem se podíval, ono to zabralo. Takže děkuji všem za spolupráci, dělal to ten appamor. Netuším kdy přesně a co přesně to udělalo, to teď budu zpětně zjištovat, ale jedno je jasné. Během instalace nějakého dodatečného softwaru to nějak nastavilo ten appamor. Díky díky díky!

[vasek]

Spíš to bylo způsobeno nějakou aktualizací.

[linuxik]

Prehlas se pres su na uzivatele s UID 200 a zkus vytvorit ten adresar rucne. Urcitr na neco prijdes.

ps. mozna budes muset v /etc/passwd zmenit posledni polozku na /bin/bash u zivatele s UID 200.