user login problem after creation

Discussion in 'Installation/Configuration' started by marcob, May 18, 2009.

  1. marcob

    marcob New Member

    Hi
    I noticed that often some users cannot login after first creation.
    Sometimes I have seen user is not created in passwd, still it's listed in ispconfig.
    Other times it's created in passwd but I have to reinsert password in ispconfig.
    Any hints?
    Thanks
     
  2. till

    till Super Moderator Staff Member ISPConfig Developer

    Take a look into the ispconfig logfile if there are any errors: /home/admispconfig/ispconfig/ispconfig.log

    Be aware that changes are not written to disk immeadeatley, it may take up to a minute or two.
     
  3. marcob

    marcob New Member

    Analyzing the logs I have noticed this behaviour:

    when for example I set again password for a user that cannot authenticate I see
    Signalfile Set: update

    Then after 30-40 seconds the following scripts are triggered:
    /root/ispconfig/scripts/lib/config.lib.php
    /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php
    /root/ispconfig/scripts/lib/classes/ispconfig_postfix.lib.php

    If I try to update password for another user or create a new user during this phase, I noticed password mismatch.

    is this something known?
     
  4. till

    till Super Moderator Staff Member ISPConfig Developer

    There are no known issues, especially as ispconfig is not starting two update processes at the same time.
     
  5. marcob

    marcob New Member

    what do you suggest to do?
     
  6. marcob

    marcob New Member

    Just tried now to create 4 users all on same domain.
    It looks it created first three correctly.
    The fourth one is not on passwd and I don't see any entries about it on ispconfig.log. Still it's listed in ispconfig.....
    What can I do...?
     
  7. marcob

    marcob New Member

    Another test:

    I changed password on 4 accounts all on same domain:
    first two works, other two doesn't
    Still I see entries in ispconfig.log but it seems it doesn't change password on last two accounts.
    This is really strange.... any workaround please?

    edit:
    Before try to change password on these 4 accounts I made a copy of /etc/shadow.
    After that changed sequentially password for these accounts
    looked at logs and after updates finished I made a diff between /etc/shadow and the copy I made before changing password.
    It showed only first two account modified while other two doesn't.
     
    Last edited: May 18, 2009
  8. marcob

    marcob New Member

    Adding:

    If I modify password of account, wait update entries in log, wait to finish, the modify password of other account, wait update entries in log, wait to finish, etc. it works.
    So it seems something related to sequentially change password. Any help will be really appreciated since this is causing a weird situation.
    Thanks again
     
  9. till

    till Super Moderator Staff Member ISPConfig Developer

    Which exact version do you use? I'am not able to reproduce that here.
     
  10. marcob

    marcob New Member

    2.2.29

    It seems it happens with account of same domain.
     
  11. till

    till Super Moderator Staff Member ISPConfig Developer

    Then update to the latest version (2.2.32) first and test again.
     
  12. marcob

    marcob New Member

    Till.
    Just to know...
    is /root/ispconfig/scripts/lib/config.lib.php the only script used to create/update users?
    Thanks
     
  13. marcob

    marcob New Member

    I upgrade succesfully to 2.2.32
    Have to say is better but sometimes problem persist.
    Test is the following:
    change password to all account of a domain (let say 6 accounts) without waiting.
    it happens che one or two of these account will have password not updated
     
  14. marcob

    marcob New Member

    Adding:

    when updating sequentially 4-5 password accounts it happens one of these did not update password, keeping old password.
    Maybe /etc/shadow is overwritten by one of the update process?
    Is there something I can do to debug this behaviour?
    Thanks again
     
  15. marcob

    marcob New Member

    Some more info and details:

    domain: test.net
    mail users: ftp, info, ciccio, ciccia, cicci, ciccione

    I sequentially change password for ciccio, ciccia, cicci, ciccione
    After that ciccia password is not updated

    Here's the logs about:

    19.05.2009 - 19:57:15 => INFO - Signalfile Set: update
    19.05.2009 - 19:57:20 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 259: setquota -r -g web24 0 0 0 0 -a &> /dev/null
    19.05.2009 - 19:57:20 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 260: setquota -r -T -g web24 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:20 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 279: Connected successfully
    19.05.2009 - 19:57:20 => INFO - USER:
    test.net_info:x:11044:11024:info:/share1/httpd/www/web24/user/test.net_info:/bin/false
    19.05.2009 - 19:57:20 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_info 0 0 0 0 -a &> /dev/null
    19.05.2009 - 19:57:20 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_info 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:20 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_info/.forward
    19.05.2009 - 19:57:21 => INFO - USER:
    test.net_ftp:x:11043:11024:ftp:/share1/httpd/www/web24:/bin/false
    19.05.2009 - 19:57:21 => INFO - Signalfile Set: update
    19.05.2009 - 19:57:25 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_ftp 0 0 0 0 -a &> /dev/null
    19.05.2009 - 19:57:25 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_ftp 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:25 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/.forward
    19.05.2009 - 19:57:26 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 117: symlink /share1/httpd/www/web24/Maildir
    19.05.2009 - 19:57:26 => INFO - USER:
    test.net_ciccione:x:12032:11024:ciccione:/share1/httpd/www/web24/user/test.net_ciccione:/bin/false
    19.05.2009 - 19:57:26 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_ciccione 51200 52224 0 0 -a &> /dev/null
    19.05.2009 - 19:57:26 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_ciccione 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:26 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_ciccione/.forward
    19.05.2009 - 19:57:27 => INFO - USER:
    test.net_cicci:x:12031:11024:cicci:/share1/httpd/www/web24/user/test.net_cicci:/bin/false
    19.05.2009 - 19:57:27 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_cicci 51200 52224 0 0 -a &> /dev/null
    19.05.2009 - 19:57:27 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_cicci 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:27 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_cicci/.forward
    19.05.2009 - 19:57:27 => INFO - Signalfile Set: update
    19.05.2009 - 19:57:27 => INFO - USER:
    test.net_ciccia:x:12030:11024:ciccia:/share1/httpd/www/web24/user/test.net_ciccia:/bin/false
    19.05.2009 - 19:57:27 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_ciccia 51200 52224 0 0 -a &> /dev/null
    19.05.2009 - 19:57:27 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_ciccia 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:27 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_ciccia/.forward
    19.05.2009 - 19:57:28 => INFO - USER:
    test.net_ciccio:x:12029:11024:ciccio:/share1/httpd/www/web24/user/test.net_ciccio:/bin/false
    19.05.2009 - 19:57:28 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_ciccio 51200 52224 0 0 -a &> /dev/null
    19.05.2009 - 19:57:28 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_ciccio 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:28 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_ciccio/.forward
    19.05.2009 - 19:57:28 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_postfix.lib.php, Line 137: cp -fr /etc/postfix/local-host-names /etc/postfix/local-host-names~
    19.05.2009 - 19:57:30 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_postfix.lib.php, Line 284: cp -fr /etc/postfix/virtusertable /etc/postfix/virtusertable~
    19.05.2009 - 19:57:30 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_postfix.lib.php, Line 289: postmap hash:/etc/postfix/virtusertable
    19.05.2009 - 19:57:30 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 1268: cp -fr /etc/apache2/vhosts/Vhosts_ispconfig.conf /etc/apache2/vhosts/Vhosts_ispconfig.conf~
    19.05.2009 - 19:57:30 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 2119: cp -fr /etc/proftpd_ispconfig.conf /etc/proftpd_ispconfig.conf~
    19.05.2009 - 19:57:33 => INFO - Signalfile Set: update
    19.05.2009 - 19:57:41 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 259: setquota -r -g web24 0 0 0 0 -a &> /dev/null
    19.05.2009 - 19:57:41 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 260: setquota -r -T -g web24 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:41 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 279: Connected successfully
    19.05.2009 - 19:57:41 => INFO - USER:
    test.net_info:x:11044:11024:info:/share1/httpd/www/web24/user/test.net_info:/bin/false
    19.05.2009 - 19:57:41 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_info 0 0 0 0 -a &> /dev/null
    19.05.2009 - 19:57:41 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_info 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:41 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_info/.forward
    19.05.2009 - 19:57:42 => INFO - USER:
    test.net_ftp:x:11043:11024:ftp:/share1/httpd/www/web24:/bin/false
    19.05.2009 - 19:57:44 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_ftp 0 0 0 0 -a &> /dev/null
    19.05.2009 - 19:57:44 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_ftp 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:44 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/.forward
    19.05.2009 - 19:57:44 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 117: symlink /share1/httpd/www/web24/Maildir
    19.05.2009 - 19:57:45 => INFO - USER:
    test.net_ciccione:x:12032:11024:ciccione:/share1/httpd/www/web24/user/test.net_ciccione:/bin/false
    19.05.2009 - 19:57:45 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_ciccione 51200 52224 0 0 -a &> /dev/null
    19.05.2009 - 19:57:45 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_ciccione 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:45 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_ciccione/.forward
    19.05.2009 - 19:57:45 => INFO - USER:
    test.net_cicci:x:12031:11024:cicci:/share1/httpd/www/web24/user/test.net_cicci:/bin/false
    19.05.2009 - 19:57:45 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_cicci 51200 52224 0 0 -a &> /dev/null
    19.05.2009 - 19:57:45 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_cicci 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:45 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_cicci/.forward
    19.05.2009 - 19:57:46 => INFO - USER:
    test.net_ciccia:x:12030:11024:ciccia:/share1/httpd/www/web24/user/test.net_ciccia:/bin/false
    19.05.2009 - 19:57:46 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_ciccia 51200 52224 0 0 -a &> /dev/null
    19.05.2009 - 19:57:46 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_ciccia 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:46 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/test.net_ciccia/.forward
    19.05.2009 - 19:57:46 => INFO - USER:
    test.net_ciccio:x:12029:11024:ciccio:/share1/httpd/www/web24/user/test.net_ciccio:/bin/false
    19.05.2009 - 19:57:46 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 910: setquota -r -u test.net_ciccio 51200 52224 0 0 -a &> /dev/null
    19.05.2009 - 19:57:46 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 911: setquota -r -T -u test.net_ciccio 604800 604800 -a &> /dev/null
    19.05.2009 - 19:57:47 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_procmail.lib.php, Line 60: cp -f /root/ispconfig/isp/conf/forward.master /share1/httpd/www/web24/user/testest.net_ciccio/.forward
    19.05.2009 - 19:57:47 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_postfix.lib.php, Line 137: cp -fr /etc/postfix/local-host-names /etc/postfix/local-host-names~
    19.05.2009 - 19:57:48 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_postfix.lib.php, Line 284: cp -fr /etc/postfix/virtusertable /etc/postfix/virtusertable~
    19.05.2009 - 19:57:48 => INFO - /root/ispconfig/scripts/lib/classes/ispconfig_postfix.lib.php, Line 289: postmap hash:/etc/postfix/virtusertable
    19.05.2009 - 19:57:49 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 1268: cp -fr /etc/apache2/vhosts/Vhosts_ispconfig.conf /etc/apache2/vhosts/Vhosts_ispconfig.conf~
    19.05.2009 - 19:57:49 => INFO - /root/ispconfig/scripts/lib/config.lib.php, Line 2119: cp -fr /etc/proftpd_ispconfig.conf /etc/proftpd_ispconfig.conf~


    what's wrong?

    Thanks
     
  16. marcob

    marcob New Member

    till
    this happens on another vmware box that I had for test too.
    If you want I can give you access to it. Please let me know what do you think.
    Thanks
     
  17. marcob

    marcob New Member

    I enabled php log.
     

    Attached Files:

  18. marcob

    marcob New Member

    apache error log
     

    Attached Files:

  19. till

    till Super Moderator Staff Member ISPConfig Developer

    I guess that the status of the processed user accounts is set to '' for all accounts at the end of a configuration run and not just for the processed accounts, so that passwords that are set during a run will not get written to /etc/passwd file. You can post a bug report to the hugtracker and it will be reviewed then for the next release.

    http://bugtracker.ispconfig.org/
     
  20. marcob

    marcob New Member


    Hi till. Is this behaviour something that is configurable anywhere? I can fill a bug report, but what can I do meanwhile? Is there a workaround that I can try to use? Thanks again for your patience.
     

Share This Page