Private repository groups shows up before login

Issue #397 resolved
ismdiego created an issue

You can find both RC and Repos folders to reproduce this in the attached ZIP file. Setup details:
Admin: admin (admin123)
Users: user1 (123456), user2 (123456)
Repository groups: Group1 & Group2 (default->none, user1->read)
Repositories: Repo1 under Group1 (default->none, user1->read)
* RC installed from scratch on clean Windows XP SP3 (english)

Problems found:

Before login, both Group1 & Group2 are shwon. They are private and they should not appear. In fact, they do not appear on "user2" home screen as expected.

Comments (11)

  1. Marcin Kuzminski repo owner

    Despite the unit and functional tests that i have for those permissions, i did create two groups, and setting none permission hide those groups for me, I did it under linux, but it really shouldn't matter. Maybe there is some specific setup that you're using and that trigger unpredictable behavior ?

  2. ismdiego reporter

    Hi Marcin,

    Did you create two users and assign one user with "read" privilege to one Repository group?

    I found this problem while using my full Rhodecode server, and then tried to isolate it in a fresh RhodeCode installation. To be precise, I use:

    • Windows XP SP3
    • Python 2.7.2
    • VirtualEnv (installs setup tools & pip)
    • Rhodecode 1.3.3 (installed with easy_install Rhodecode + VS2008 C++ express installed on Win machine)
    • Using all defaults (not modifying production.ini file)

    Anyway, I will try again with another fresh install, just in case I mixed some thing up. I am still trying to reproduce another issue that I have in my production server in a fresh install but I can not.

    Thanks for your work

  3. ismdiego reporter

    I put console and DEBUG to all log handlers, and this is my output when accessing http://localhost:5000 (no user and passw entered yet):

    Starting server in PID 3060.
    serving on http://127.0.0.1:5000
    2012-03-12 17:30:50.530 INFO  [rhodecode.lib.base] User: <AuthUser('id:1:default|True')> accessed /
    2012-03-12 17:30:50.530 INFO  [rhodecode.lib.base] User: <AuthUser('id:1:default|True')> accessed /
    2012-03-12 17:30:50.546 INFO  [rhodecode.lib.auth] user default is authenticated and granted access to HomeController:__before__
    2012-03-12 17:30:50.546 INFO  [rhodecode.lib.auth] user default is authenticated and granted access to HomeController:__before__
    2012-03-12 17:30:50.750 INFO  [rhodecode.lib.base] Request to / time: 0.235s
    2012-03-12 17:30:50.750 INFO  [rhodecode.lib.base] Request to / time: 0.235s
    

    RESULT: the two private repositories are shown (not expected)

    Then, I log with "user2" (this user has no permissions over the two repository groups):

    2012-03-12 17:33:05.217 INFO  [rhodecode.lib.base] User: <AuthUser('id:1:default|True')> accessed /_admin/login
    2012-03-12 17:33:05.217 INFO  [rhodecode.lib.base] User: <AuthUser('id:1:default|True')> accessed /_admin/login
    2012-03-12 17:33:05.233 INFO  [rhodecode.lib.auth] user user2 authenticated correctly
    2012-03-12 17:33:05.233 INFO  [rhodecode.lib.auth] user user2 authenticated correctly
    2012-03-12 17:33:05.250 INFO  [rhodecode.controllers.login] user user2 is now authenticated and stored in session, session attrs {'username': u'user2', 'is_authenticated': True, 'user_id': 4}
    2012-03-12 17:33:05.250 INFO  [rhodecode.controllers.login] user user2 is now authenticated and stored in session, session attrs {'username': u'user2', 'is_authenticated': True, 'user_id': 4}
    2012-03-12 17:33:05.265 INFO  [rhodecode.lib.base] Request to /_admin/login time: 0.078s
    2012-03-12 17:33:05.265 INFO  [rhodecode.lib.base] Request to /_admin/login time: 0.078s
    2012-03-12 17:33:05.312 INFO  [rhodecode.lib.base] User: <AuthUser('id:4:user2|True')> accessed /
    2012-03-12 17:33:05.312 INFO  [rhodecode.lib.base] User: <AuthUser('id:4:user2|True')> accessed /
    2012-03-12 17:33:05.312 INFO  [rhodecode.lib.auth] user user2 is authenticated and granted access to HomeController:__before__
    2012-03-12 17:33:05.312 INFO  [rhodecode.lib.auth] user user2 is authenticated and granted access to HomeController:__before__
    2012-03-12 17:33:05.328 INFO  [rhodecode.lib.base] Request to / time: 0.047s
    2012-03-12 17:33:05.328 INFO  [rhodecode.lib.base] Request to / time: 0.047s
    

    RESULT: No repository group is shown (as expected)

  4. ismdiego reporter

    By the way, could you reproduce the issue with the attached zip file? if not, how can I send you my full RC setup?

    It's a really simple installation (in Windows):

    • Python in C:\Python27
    • RC data in C:\RC
    • Repositories in C:\Repos

    Regards

  5. Marcin Kuzminski repo owner

    Something here is odd, if you enabled DEBUG, why there are only INFO statements shown ? IT should contain a bunch of DEBUG statements

  6. ismdiego reporter

    Sorry Marcin, I forgot to put DEBUG on the console handler (I put DEBUG on all the loggers).

    This time there is more information. This is the output when accessing http://localhost:5000

    2012-03-12 18:35:17.233 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:35:17.405 DEBUG [rhodecode.lib.middleware.simplegit] is a git path None pathinfo : /
    2012-03-12 18:35:17.483 DEBUG [routes.middleware] Matched GET /
    2012-03-12 18:35:17.483 DEBUG [routes.middleware] Route path: '/', defaults: {'action': u'index', 'controller': u'home'}
    2012-03-12 18:35:17.483 DEBUG [routes.middleware] Match dict: {'action': u'index', 'controller': u'home'}
    2012-03-12 18:35:17.483 DEBUG [pylons.wsgiapp] Setting up Pylons stacked objectglobals
    2012-03-12 18:35:17.500 DEBUG [pylons.wsgiapp] Resolved URL to controller: u'home'
    2012-03-12 18:35:17.500 DEBUG [pylons.wsgiapp] Found controller, module: 'rhodecode.controllers.home', class: 'HomeController'
    2012-03-12 18:35:17.500 DEBUG [pylons.wsgiapp] Controller appears to be a class, instantiating
    2012-03-12 18:35:17.500 DEBUG [pylons.wsgiapp] Calling controller class with WSGI interface
    2012-03-12 18:35:17.500 DEBUG [beaker.container] lock_createfunc (waiting)
    2012-03-12 18:35:17.500 DEBUG [beaker.container] lock_createfunc (waited)
    2012-03-12 18:35:17.500 DEBUG [beaker.container] get_value creating new value
    2012-03-12 18:35:17.515 DEBUG [beaker.container] set_value stored time 1331573717.515 expire time 10
    2012-03-12 18:35:17.515 DEBUG [beaker.container] released create lock
    2012-03-12 18:35:17.515 DEBUG [rhodecode.lib.auth] No data in <AuthUser('id:None:None|False')> that could been used to log in
    2012-03-12 18:35:17.515 DEBUG [rhodecode.model.user] filling <User('id:1:default')> data
    2012-03-12 18:35:17.515 DEBUG [rhodecode.lib.auth] Auth User is now <AuthUser('id:1:default|True')>
    2012-03-12 18:35:17.530 INFO  [rhodecode.lib.base] User: <AuthUser('id:1:default|True')> accessed /
    2012-03-12 18:35:17.546 DEBUG [pylons.controllers.core] Calling '__before__' method with keyword args: **{}
    2012-03-12 18:35:17.546 DEBUG [rhodecode.lib.auth] Checking if default is authenticated @ HomeController:__before__
    2012-03-12 18:35:17.546 INFO  [rhodecode.lib.auth] user default is authenticated and granted access to HomeController:__before__
    2012-03-12 18:35:17.546 DEBUG [pylons.controllers.core] Looking for u'index' method to handle the request
    2012-03-12 18:35:17.546 DEBUG [pylons.controllers.core] Calling 'index' method with keyword args: **{}
    2012-03-12 18:35:17.562 DEBUG [rhodecode.lib.auth] checking HasPermissionAll set(['hg.admin']) <AuthUser('id:1:default|True')>
    2012-03-12 18:35:17.562 DEBUG [rhodecode.lib.auth] Permission denied for <AuthUser('id:1:default|True')> @ access admin main page
    2012-03-12 18:35:17.562 DEBUG [rhodecode.lib.auth] checking HasPermissionAny set(['hg.admin', 'hg.register.auto_activate', 'hg.register.manual_activate']) <AuthUser('id:1:default|True')>
    2012-03-12 18:35:17.562 DEBUG [rhodecode.lib.auth] Permission granted <AuthUser('id:1:default|True')> @ unspecified location
    2012-03-12 18:35:17.578 DEBUG [rhodecode.lib.auth] checking HasReposGroupPermissionAny set(['group.admin', 'group.read', 'group.write']) <AuthUser('id:1:default|True')>
    2012-03-12 18:35:17.578 DEBUG [rhodecode.lib.auth] Permission granted None @ get group repo check
    2012-03-12 18:35:17.578 DEBUG [rhodecode.lib.auth] checking HasReposGroupPermissionAny set(['group.admin', 'group.read', 'group.write']) <AuthUser('id:1:default|True')>
    2012-03-12 18:35:17.578 DEBUG [rhodecode.lib.auth] Permission granted None @ get group repo check
    2012-03-12 18:35:17.578 DEBUG [pylons.controllers.core] Controller returned a unicode string , writing it to pylons.response
    2012-03-12 18:35:17.578 DEBUG [pylons.controllers.core] Calling Response objectto return WSGI data
    2012-03-12 18:35:17.608 DEBUG [beaker.container] data file C:\RC/data\sessions/container_file\3\36\3605ff51759e4a309832af55047e512d.cache
    2012-03-12 18:35:17.608 INFO  [rhodecode.lib.base] Request to / time: 0.109s
    2012-03-12 18:35:17.608 DEBUG [rhodecode.SimpleHg] Request time: 0.203s
    2012-03-12 18:35:17.608 DEBUG [rhodecode.SimpleGit] Request time: 0.203s
    
  7. ismdiego reporter

    And this is the result after "user2" logs in (and the two private repository groups disappear):

    2012-03-12 18:43:37.375 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:43:37.375 DEBUG [rhodecode.lib.middleware.simplegit] is a git path None pathinfo : /_admin/login
    2012-03-12 18:43:37.375 DEBUG [routes.middleware] Matched POST /_admin/login
    2012-03-12 18:43:37.375 DEBUG [routes.middleware] Route path: '/_admin/login', defaults: {'action': u'index', 'controller': u'login'}
    2012-03-12 18:43:37.375 DEBUG [routes.middleware] Match dict: {'action': u'index', 'controller': u'login'}
    2012-03-12 18:43:37.375 DEBUG [pylons.wsgiapp] Setting up Pylons stacked objectglobals
    2012-03-12 18:43:37.375 DEBUG [pylons.wsgiapp] Resolved URL to controller: u'login'
    2012-03-12 18:43:37.437 DEBUG [pylons.wsgiapp] Found controller, module: 'rhodecode.controllers.login', class: 'LoginController'
    2012-03-12 18:43:37.453 DEBUG [pylons.wsgiapp] Controller appears to be a class, instantiating
    2012-03-12 18:43:37.453 DEBUG [pylons.wsgiapp] Calling controller class with WSGI interface
    2012-03-12 18:43:37.453 DEBUG [beaker.container] data file C:\RC/data\sessions/container_file\1\14\14fb9522bc684985ac37e255833e7def.cache
    2012-03-12 18:43:37.453 DEBUG [beaker.container] lock_creatfunc (didnt wait)
    2012-03-12 18:43:37.453 DEBUG [beaker.container] get_value creating new value
    2012-03-12 18:43:37.453 DEBUG [beaker.container] set_value stored time 1331574217.453 expire time 10
    2012-03-12 18:43:37.453 DEBUG [beaker.container] released create lock
    2012-03-12 18:43:37.453 DEBUG [rhodecode.lib.auth] No data in <AuthUser('id:None:None|False')> that could been used to log in
    2012-03-12 18:43:37.453 DEBUG [rhodecode.model.user] filling <User('id:1:default')> data
    2012-03-12 18:43:37.453 DEBUG [rhodecode.lib.auth] Auth User is now <AuthUser('id:1:default|True')>
    2012-03-12 18:43:37.483 INFO  [rhodecode.lib.base] User: <AuthUser('id:1:default|True')> accessed /_admin/login
    2012-03-12 18:43:37.483 DEBUG [pylons.controllers.core] Calling '__before__' method with keyword args: **{}
    2012-03-12 18:43:37.483 DEBUG [pylons.controllers.core] Looking for u'index' method to handle the request
    2012-03-12 18:43:37.500 DEBUG [pylons.controllers.core] Calling 'index' method with keyword args: **{}
    2012-03-12 18:43:37.500 DEBUG [rhodecode.lib.auth] Authenticating user using RhodeCode account
    2012-03-12 18:43:37.500 INFO  [rhodecode.lib.auth] user user2 authenticated correctly
    2012-03-12 18:43:37.500 DEBUG [rhodecode.lib.auth] Auth User lookup by USER ID 4
    2012-03-12 18:43:37.500 DEBUG [rhodecode.model.user] filling <User('id:4:user2')> data
    2012-03-12 18:43:37.500 DEBUG [rhodecode.lib.auth] Auth User is now <AuthUser('id:4:user2|False')>
    2012-03-12 18:43:37.515 INFO  [rhodecode.controllers.login] user user2 is now authenticated and stored in session, session attrs {'username': u'user2', 'is_authenticated': True, 'user_id': 4}
    2012-03-12 18:43:37.515 DEBUG [rhodecode.model.db] updated user user2 lastlogin
    2012-03-12 18:43:37.546 DEBUG [pylons.controllers.util] Generating 302 redirect
    2012-03-12 18:43:37.546 DEBUG [pylons.controllers.core] 'index' method raised HTTPException: HTTPFound (code: 302)
    Traceback (most recent call last):
      File "c:\Env1\lib\site-packages\pylons-1.0-py2.7.egg\pylons\controllers\core.py", line 105, in _inspect_call
        result = self._perform_call(func, args)
      File "c:\Env1\lib\site-packages\pylons-1.0-py2.7.egg\pylons\controllers\core.py", line 57, in _perform_call
        return func(**args)
      File "c:\Env1\lib\site-packages\rhodecode-1.3.3-py2.7.egg\rhodecode\controllers\login.py", line 86, in index
        return redirect(c.came_from)
      File "c:\Env1\lib\site-packages\pylons-1.0-py2.7.egg\pylons\controllers\util.py", line 208, in redirect
        raise exc(location=url).exception
    HTTPFound: The resource was found at
    2012-03-12 18:43:37.546 DEBUG [pylons.controllers.core] Controller returned a Response object, merging it with pylons.response
    2012-03-12 18:43:37.546 DEBUG [pylons.controllers.core] Calling Response objectto return WSGI data
    2012-03-12 18:43:37.562 INFO  [rhodecode.lib.base] Request to /_admin/login time: 0.109s
    2012-03-12 18:43:37.562 DEBUG [rhodecode.SimpleHg] Request time: 0.187s
    2012-03-12 18:43:37.562 DEBUG [rhodecode.SimpleGit] Request time: 0.187s
    2012-03-12 18:43:37.562 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasks queued)
    2012-03-12 18:43:37.562 DEBUG [rhodecode.lib.middleware.simplegit] is a git path None pathinfo : /
    2012-03-12 18:43:37.578 DEBUG [routes.middleware] Matched GET /
    2012-03-12 18:43:37.578 DEBUG [routes.middleware] Route path: '/', defaults: {'action': u'index', 'controller': u'home'}
    2012-03-12 18:43:37.578 DEBUG [routes.middleware] Match dict: {'action': u'index', 'controller': u'home'}
    2012-03-12 18:43:37.578 DEBUG [pylons.wsgiapp] Setting up Pylons stacked objectglobals
    2012-03-12 18:43:37.578 DEBUG [pylons.wsgiapp] Resolved URL to controller: u'home'
    2012-03-12 18:43:37.578 DEBUG [pylons.wsgiapp] Controller appears to be a class, instantiating
    2012-03-12 18:43:37.578 DEBUG [pylons.wsgiapp] Calling controller class with WSGI interface
    2012-03-12 18:43:37.578 DEBUG [beaker.container] data file C:\RC/data\sessions/container_file\1\14\14fb9522bc684985ac37e255833e7def.cache
    2012-03-12 18:43:37.578 DEBUG [rhodecode.lib.auth] Auth User lookup by USER ID 4
    2012-03-12 18:43:37.592 DEBUG [rhodecode.model.user] filling <User('id:4:user2')> data
    2012-03-12 18:43:37.592 DEBUG [rhodecode.lib.auth] Auth User is now <AuthUser('id:4:user2|False')>
    2012-03-12 18:43:37.608 INFO  [rhodecode.lib.base] User: <AuthUser('id:4:user2|True')> accessed /
    2012-03-12 18:43:37.608 DEBUG [pylons.controllers.core] Calling '__before__' method with keyword args: **{}
    2012-03-12 18:43:37.608 DEBUG [rhodecode.lib.auth] Checking if user2 is authenticated @ HomeController:__before__
    2012-03-12 18:43:37.608 INFO  [rhodecode.lib.auth] user user2 is authenticated and granted access to HomeController:__before__
    2012-03-12 18:43:37.625 DEBUG [pylons.controllers.core] Looking for u'index' method to handle the request
    2012-03-12 18:43:37.625 DEBUG [pylons.controllers.core] Calling 'index' method with keyword args: **{}
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] checking HasPermissionAll set(['hg.admin']) <AuthUser('id:4:user2|True')>
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] Permission denied for <AuthUser('id:4:user2|True')> @ access admin main page
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] checking HasPermissionAny set(['hg.admin', 'hg.create.repository']) <AuthUser('id:4:user2|True')>
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] Permission granted <AuthUser('id:4:user2|True')> @ unspecified location
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] checking HasReposGroupPermissionAny set(['group.admin', 'group.read', 'group.write']) <AuthUser('id:4:user2|True')>
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] Permission denied for None @get group repo check
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] checking HasReposGroupPermissionAny set(['group.admin', 'group.read', 'group.write']) <AuthUser('id:4:user2|True')>
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] Permission denied for None @get group repo check
    2012-03-12 18:43:37.625 DEBUG [pylons.controllers.core] Controller returned a unicode string , writing it to pylons.response
    2012-03-12 18:43:37.640 DEBUG [pylons.controllers.core] Calling Response objectto return WSGI data
    2012-03-12 18:43:37.640 INFO  [rhodecode.lib.base] Request to / time: 0.062s
    2012-03-12 18:43:37.640 DEBUG [rhodecode.SimpleHg] Request time: 0.062s
    2012-03-12 18:43:37.640 DEBUG [rhodecode.SimpleGit] Request time: 0.078s
    2012-03-12 18:43:37.655 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:43:37.655 DEBUG [paste.httpserver.ThreadPool] Added task (1 tasksqueued)
    2012-03-12 18:43:37.671 DEBUG [paste.httpserver.ThreadPool] Added task (1 tasksqueued)
    2012-03-12 18:43:37.671 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:43:37.687 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:43:37.796 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:43:37.796 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:43:37.812 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:43:37.812 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    2012-03-12 18:43:37.858 DEBUG [paste.httpserver.ThreadPool] Added task (0 tasksqueued)
    
  8. ismdiego reporter

    After quickly examining logs, I think the interesting bits in the first case maybe are here:

    2012-03-12 18:35:17.578 DEBUG [rhodecode.lib.auth] checking HasReposGroupPermissionAny set(['group.admin', 'group.read', 'group.write']) <AuthUser('id:1:default|True')>
    2012-03-12 18:35:17.578 DEBUG [rhodecode.lib.auth] Permission granted None @ get group repo check
    

    Permission GRANTED None... and then it shows the repository groups.

    Later, when user2 logs, the log says:

    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] checking HasReposGroupPermissionAny set(['group.admin', 'group.read', 'group.write']) <AuthUser('id:4:user2|True')>
    2012-03-12 18:43:37.625 DEBUG [rhodecode.lib.auth] Permission denied for None @get group repo check
    

    Permission DENIED None, the repository group is not shown.

    Something should be wrong. I don't know the internals of this, I hope these logs help you.

  9. Log in to comment