Bonjour à tous,
 
Je possede un serveur Linux FC3 avec Postfix/Mysql/SALS2/Postfixadmin qui fonctionne bien sauf 1 truc.
 
J'utilise pam-mysql pour authentifier mes utilisateurs,ca fonctionne au poil SAUF que une partie  des
logs ne fonctionnent pas.
 
Je m'explique:
dans /etc/pam.d/smtp (qui utilise la librairie pam-mysql), je demande lors de chaque connexion via SMTP, une entrée dans la base de données soit inscrite. La mise ajour dans la base se passe bien SAUF que la donnée inscrite dans le champ loghostcolumn est toujours unknown (pas de soucis pour les autres champs).
 
j'essaie d'activer les logs pour pam afin de voir pourquoi la valeur est unknow a la place de l'adresse IP, mais je n'y arrive pas.
 
Voila, si quelqu'un a une idée?
 

bonjour
il faudrait voir ton fichier /etc/pam.d/smtp
 
tu veux logguer le hostname du client qui s'authentifie ?  
as tu verifié ta resolution dns ?
compare aussi avec ce que voit postfix dans ces logs sur le hostname du client

As tu bien lancé ton serveur MySQL ? Sinon reboot ta machine.

bien vu, toniotonio, je n'avais pas pensé aux logs de postfix :-(
 
je vais jeter un coup d'oeil pour voir comment postfix voit la machine
 
mais il ne stocke pas le nom DNS (d'apres le readme de pam-mysql), mais l'adresse IP.
 
Merci pour ta réponse rapide!!

en fait, Postfix voit bien ma machine emettrice (@ IP et nom d'hote),
il fait une succession de match_hostname avec le nom FQDN en comparaison avec la valeur de $mynetwork jusqu'a comparer l'@IP de la machine emettrice avec l'@IP de $mynetwork
 
mais  lors de l'insertion dans la base via le demon saslauthd, il insert toutes les colonnes mais celle de loghostcolumn, il ajoute 'unknown'.
 
ai-je été assez clair??
 

il faudrait voir le script que tu utilises pour bien comprendre
mais je pense que mettre le demon saslauthd en verbose devrait t'aider a debugger

je n'utilise pas de script, juste le module pam_mysql.
 
en fait le demon sasl n'est la que pour l'authentification, c'est pam_mysql qui met a jour la base de donnée (par l'intermediaire de postfix).
 

je voulais dire le contenu de /etc/pam.d/smtp

auth            sufficient      pam_mysql.so host=localhost db=postfix user=postfix passwd=*** table=mailbox usercolumn=username passwdcolumn=password crypt=1 verbose=1 sqllog=yes logtable=connection logmsgcolumn=action logusercolumn=username logpidcolumn=pid loghostcolumn=host logtimecolumn=timestamp
 
account         required        pam_mysql.so host=localhost db=postfix user=postfix passwd=*** table=mailbox usercolumn=username passwdcolumn=password crypt=1 verbose=1 sqllog=yes logtable=connection logmsgcolumn=action logusercolumn=username logpidcolumn=pid loghostcolumn=host logtimecolumn=timestamp where=mailbox.active=1  
 
rien d'extraordinaire, n'est-ce pas!

je vois que le verbose est activé  
tu as quoi dans /var/log/messages (ou ailleurs) en rapport avec pam-mysql ?
 
sinon j'avais lu une fois un pb sur le sujet, comme quoi cela pouvait etre saslauthd qui ne transmet pas l'information (ou du moins correectemtn)
essaie de mettre saslauthd en debug egalement

salsauth me fourni  des logs d'authentification de type [auth success] etc... bon une capture vaut mieux plus qu'un long discours:
 
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - option verbose is set to "1"
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - option sqllog is set to "yes"
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - option logtable is set to "connection"
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - option logmsgcolumn is set to "action"
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - option logusercolumn is set to "username"
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - option logpidcolumn is set to "pid"
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - option loghostcolumn is set to "host"
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - option logtimecolumn is set to "timestamp"
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_close_db() called.
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_sm_authenticate() called.
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_converse() called.
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_open_db() called.
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_open_db() returning 0.
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_check_passwd() called.
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_format_string() called
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_quick_escape() called.
Apr 11 15:19:36 test-postfix last message repeated 3 times
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - SELECT password FROM mailbox WHERE username = 'toto@toto.com'
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_sql_log() called.
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_format_string() called
Apr 11 15:19:36 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_quick_escape() called.
Apr 11 15:19:37 test-postfix last message repeated 8 times
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - INSERT INTO log_connection (action, username, host, pid, timestamp) VALUES ('AUTHENTICATION SUCCESS', 'toto@toto.com', '(unknown)', '28201', NOW())
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_sql_log() returning 0.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_check_passwd() returning 0.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_sm_authenticate() returning 0.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option host is set to "localhost"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option db is set to "postfix"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option user is set to "postfix"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option passwd is set to "postfix"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option table is set to "mailbox"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option usercolumn is set to "username"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option passwdcolumn is set to "password"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option crypt is set to "1"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option verbose is set to "1"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option sqllog is set to "yes"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option logtable is set to "connection"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option logmsgcolumn is set to "action"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option logusercolumn is set to "username"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option logpidcolumn is set to "pid"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option loghostcolumn is set to "host"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option logtimecolumn is set to "timestamp"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - option where is set to "mailbox.active=1"
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_close_db() called.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_sm_acct_mgmt() called.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_open_db() called.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_open_db() returning 0.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_query_user_stat() called.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_format_string() called
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_quick_escape() called.
Apr 11 15:19:37 test-postfix last message repeated 5 times
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - SELECT 0, password FROM mailbox WHERE username = 'toto@toto.com' AND (mailbox.active=1)
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_sql_log() called.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_format_string() called
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_quick_escape() called.
Apr 11 15:19:37 test-postfix last message repeated 8 times
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - INSERT INTO log_connection (action, username, host, pid, timestamp) VALUES ('QUERYING SUCCESS', 'toto@toto.com', '(unknown)', '28201', NOW())
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_sql_log() returning 0.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_query_user_stat() returning 0.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_sm_acct_mgmt() returning 0.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_release_ctx() called.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_destroy_ctx() called.
Apr 11 15:19:37 test-postfix saslauthd[28201]: pam_mysql - pam_mysql_close_db() called.
Apr 11 15:19:37 test-postfix saslauthd[28201]: do_auth         : auth success: [user=toto@toto.com] [service=smtp] [realm=toto.com] [mech=pam]
 
 

tu peux poster le fichier smtpd.conf ?
 
avec quels parametres demarre tu saslauthd ?
 
ton postifx est il chrooté ?
 

de retour...
 
smtpd.conf
pwcheck_method: saslauthd
mech_list: LOGIN PLAIN
 
saslauthd
-r -a pam  
postfix non 'chrooté'

est ce que tu as mis le demon saslauthd en debug (par le parametre -d) ou bien uniquement pam-mysql ?
 
il faudrait voir les infos qu'il envoie
 

je pensais a un truc:
essaie de mettre host=127.0.0.1 a la place de  host=localhost dans /etc/pam.d/smtp

en fait, c'est le post du 11/04 a 16.31. saslauth est en mode debug -v.
et on voit bien pam_mysql qui insert les lignes dans la table.
 
par contre, mettre l'extension pam_mysql en debug, je ne sais pas si c'est possible...

 
 
mets plutot saslauthd en debug par le parametre -d
 
pam_mysql est deja en verbose et c'est suffisant pour l'isntant
 
mais essaie de faire aussi ce que j'ai posté il y a 2 minutes (juste aussus)

idem avec 127.0.0.1 !

ok alors essaie le debug avec -d

les logs du 11/04 à 16.31 sont fait avec -d -V

peux tu aussi mettre le log de postifx qui montre la connection   (avec l'ip du client)

et essaie de demarrer saslauthd en console avec le parametre -d   (pas dans init.d)
 
edit: bien sur met egalement les autres parametres a la main

c'est ce que j'ai fait
 
bon on va y arriver ou bien ;-)
 
pour les logs de postfix, je les post apres

 
quelles sont les versions de saslauthd, pam_mysql et postifx ?

et dans /var/log/auth.log tu as quoi ?

le socket de salsauthd est ou ?
 
a priori il devrait etre dans /var/spool/postfix/var/run
 
verifie aussi ce point

c'est une bonne question, on aurais du commencer par la:
postfix 2.3.3-2 en src.rpm (provenant de http://postfix.wl0.org/en/building-rpms)
 
sasl: 2.1.19
pam_mysql : 0.6.2-2

les version sont assez recentes donc a priori c'est pas ca.
 
ps : tu as vu mes autres posts ?

oui, je les ai vu, le socket est dans /var/run/saslauthd

essaye de le mettre dans /var/spool/postfix/var/run/saslauthd
 
ajoute un parametre a saslauthd:

 
puis ajoute postfic au groupe sasl
 

 
 
verifie bien les droits du repertoire  

mais j'ai compilé pam_mysql 0.7 et j'ai cette fois l'adresse IP
 
MAIS, j'ai une requete en plus!!
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - INSERT INTO connection (action, username, host, pid, timestamp) VALUES ('AUTHENTICATION FALURE (FIRST_PASS)', 'toto@toto.com', '192.168.1.2', '13577', NOW())
 
 
ci apres le contenu global de /var/log/secure.log
 
Apr 12 14:25:14 postfix saslauthd[13577]: rel_accept_lock : released accept lock
Apr 12 14:25:14 postfix saslauthd[13578]: get_accept_lock : acquired accept lock
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option verbose is set to "1"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option sqllog is set to "yes"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logtable is set to "connection"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logmsgcolumn is set to "action"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logusercolumn is set to "username"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logpidcolumn is set to "pid"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option loghostcolumn is set to "host"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logtimecolumn is set to "timestamp"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_close_db() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_sm_authenticate() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_open_db() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_open_db() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_check_passwd() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_format_string() called
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_quick_escape() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - SELECT password FROM mailbox WHERE username = 'toto@toto.com'
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_check_passwd() returning 6.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_sql_log() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_format_string() called
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_quick_escape() called.
Apr 12 14:25:14 postfix last message repeated 2 times
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - INSERT INTO connection (action, username, host, pid, timestamp) VALUES ('AUTHENTICATION FALURE (FIRST_PASS)', 'toto@toto.com', '192.168.1.2', '13577', NOW())
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_sql_log() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_converse() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_open_db() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_check_passwd() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_format_string() called
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_quick_escape() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - SELECT password FROM mailbox WHERE username = 'toto@toto.com'
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_check_passwd() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_sql_log() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_format_string() called
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_quick_escape() called.
Apr 12 14:25:14 postfix last message repeated 2 times
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - INSERT INTO connection (action, username, host, pid, timestamp) VALUES ('AUTHENTICATION SUCCESS', 'toto@toto.com', '192.168.1.2', '13577', NOW())
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_sql_log() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_sm_authenticate() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option host is set to "127.0.0.1"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option db is set to "postfix"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option user is set to "postfix"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option passwd is set to "postfix"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option table is set to "mailbox"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option usercolumn is set to "username"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option passwdcolumn is set to "password"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option crypt is set to "1"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option verbose is set to "1"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option sqllog is set to "yes"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logtable is set to "connection"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logmsgcolumn is set to "action"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logusercolumn is set to "username"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logpidcolumn is set to "pid"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option loghostcolumn is set to "host"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option logtimecolumn is set to "timestamp"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - option where is set to "mailbox.active=1"
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_close_db() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_sm_acct_mgmt() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_open_db() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_open_db() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_query_user_stat() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_format_string() called
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_quick_escape() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - SELECT 0, password FROM mailbox WHERE username = 'toto@toto.com' AND (mailbox.active=1)
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_query_user_stat() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_sql_log() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_format_string() called
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_quick_escape() called.
Apr 12 14:25:14 postfix last message repeated 2 times
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - INSERT INTO connection (action, username, host, pid, timestamp) VALUES ('QUERYING SUCCESS', 'toto@toto.com', '192.168.1.2', '13577', NOW())
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_sql_log() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_sm_acct_mgmt() returning 0.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_release_ctx() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_destroy_ctx() called.
Apr 12 14:25:14 postfix saslauthd[13577]: pam_mysql - pam_mysql_close_db() called.

donc ca marche ?
bon a savoir ca qu'il fallait upgradé pam_mysql

oui, mais j'ai une entrée dans ma base de donnée en plus qui ne veur rien dire:
 
NSERT INTO connection (action, username, host, pid, timestamp) VALUES ('AUTHENTICATION FALURE (FIRST_PASS)', 'toto@toto.com', '192.168.1.2', '13577', NOW())  
 
donc, pour moi, ce n'est pas encore bon!!!

 
 
j'ai manqué un truc
le pb c'est quoi exactment ?

ben en fait, c'est que, j'ai une ligne de log en plus qui dit:
'AUTHENTICATION FALURE (FIRST_PASS)', 'toto@toto.com', '192.168.1.2', '13577', NOW())  
 
alors que non, il n'y a pas de pb de connexion!!

quelle version exactement de pam_mysql ?
 
 

celle que j'ai compilé, c'est la 0.7RC1

probleme résolu, je n'avais pas lu entierement le README de pam_mysql.
 
Il faut, dans mon cas, desactiver l'option try_first_pass dans /etc/pam.d/smtp!!
 
merci encore pour ta collaboration assidue, toniotonio!

je suis un peu degouté, car l'adresse IP qui est logué n'est pas celle du client mais du serveur (je faisait mes tests en local sur la machine Postfix)
 
a priori faut se servir de la variable logrhostcolumn avec "the PAM-aware application?!?)
 
degouté...