Kallithea issues archive

PS: the Kallithea I use for the IIS hosting is running fine on http://localhost:5000 when I start it with "paster serve my.ini"

I am not familiar at all with IIS, so I can only give some general questions:

1. You say that you can get a (unstyled) login page. However, Kallithea is by default accessible without login (unless you changed its settings). I would thus expect that at the main URL you can see something without login. Is that the case? I guess it is also unstyled?

2. What is the URL at which Kallithea is supposed to be present? What is the URL of the login page? Is Kallithea indeed hosted at the root of the server?

3. In your Kallithea ini file, could you check if DEBUG logging is enabled? Specifically, near the bottom, check this block:

[logger_kallithea]
level = DEBUG
handlers =
qualname = kallithea
propagate = 1

and this one, a bit lower:

[handler_console]
class = StreamHandler
args = (sys.stderr,)
level = DEBUG
formatter = generic

After you changed this, restart Kallithea and check if anything more useful comes up in the trace output via win32traceutil.

I am also not very familiar with IIS (just learned what I needed to know to get things running) and also new to Kallithea so it's a steep learning curve for me. So far I hosted Hg repos on IIS 6 with hgweb.cgi but Kallithea sounded like a promising improvement over the current installation, especially the possiblity of getting Single-Sign-On capability.

You say that you can get a (unstyled) login page. However, Kallithea is by default accessible without login (unless you changed its settings). I >would thus expect that at the main URL you can see something without login. Is that the case? I guess it is also unstyled?

My description was not precise - what I see is a unstyled version of the Kallithea start page (which also has the login section) - as you can see in the screenshot that I attached to my original post.

What is the URL at which Kallithea is supposed to be present? What is the URL of the login page? Is Kallithea indeed hosted at the root of the server?

The URL is supposed to be http://hg2.vision.local which is the one I tested and is showing the unstyled start page Kallithea (db and ini file) are indeed at the root of the IIS webpage which is at C:\inetpub\kallithea

I increased logging of [handler_console] from INFO to DEBUG, [logger_kallithea] was already set as described. When I access the Kallithea page now I get a lot more info but nothing that shows why the page is unstyled. Maybe you can find something, here is the output:

C:\inetpub\kallithea>python -m win32traceutil
Collecting Python Trace Output...
2018-01-21 09:43:01.992 DEBUG [pylons.configuration] Initializing configuration, package: 'kallithea'
2018-01-21 09:43:02.085 INFO  [kallithea.model] initializing db for sqlite:///C:\inetpub\kallithea/kallithea.db?timeout=60
2018-01-21 09:43:02.085 INFO  [kallithea.lib.auth] getting information about all available permissions
2018-01-21 09:43:02.226 DEBUG [kallithea.lib.utils] settings ui from db: [hooks] changegroup.repo_size=python:kallithea.lib.hooks.repo_size
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [hooks] changegroup.push_logger=python:kallithea.lib.hooks.log_push_action
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [hooks] prechangegroup.pre_push=python:kallithea.lib.hooks.pre_push
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [hooks] outgoing.pull_logger=python:kallithea.lib.hooks.log_pull_action
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [hooks] preoutgoing.pre_pull=python:kallithea.lib.hooks.pre_pull
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [extensions] largefiles=
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [largefiles] usercache=F:\Kallithea\Repos\.cache\largefiles
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [web] push_ssl=false
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [web] allow_archive=gz zip bz2
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [web] allow_push=*
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [web] baseurl=/
2018-01-21 09:43:02.242 DEBUG [kallithea.lib.utils] settings ui from db: [paths] /=F:\Kallithea\Repos
2018-01-21 09:43:02.257 DEBUG [routes.middleware] Initialized with method overriding = True, and path info altering = True
2018-01-21 09:43:02.273 DEBUG [kallithea.lib.middleware.simplegit] pathinfo: / detected as Git False
2018-01-21 09:43:02.273 DEBUG [kallithea.lib.middleware.simplehg] pathinfo: / detected as Mercurial False
2018-01-21 09:43:02.446 DEBUG [routes.middleware] Matched GET /
2018-01-21 09:43:02.446 DEBUG [routes.middleware] Route path: '/', defaults: {'action': u'index', 'controller': u'home'}
2018-01-21 09:43:02.446 DEBUG [routes.middleware] Match dict: {'action': u'index', 'controller': u'home'}
2018-01-21 09:43:02.446 DEBUG [pylons.wsgiapp] Setting up Pylons stacked object globals
2018-01-21 09:43:02.446 DEBUG [pylons.wsgiapp] Resolved URL to controller: u'home'
2018-01-21 09:43:02.460 DEBUG [pylons.wsgiapp] Found controller, module: 'kallithea.controllers.home', class: 'HomeController'
2018-01-21 09:43:02.460 DEBUG [pylons.wsgiapp] Controller appears to be a class, instantiating
2018-01-21 09:43:02.460 DEBUG [pylons.wsgiapp] Calling controller class with WSGI interface
2018-01-21 09:43:02.460 DEBUG [beaker.container] data file C:\inetpub\kallithea/data\sessions/container_file\3\36\36198ec4e2804cf3ba6bae8116c5f077.cache
2018-01-21 09:43:03.937 DEBUG [kallithea.lib.auth_modules] Importing kallithea.lib.auth_modules.auth_internal
2018-01-21 09:43:03.937 DEBUG [kallithea.lib.auth_modules] Loaded auth plugin from kallithea.lib.auth_modules.auth_internal (module:kallithea.lib.auth_modules.auth_internal, file:C:\Python27\lib\site-packages\kallithea\lib\auth_modules\auth_internal.pyc)
2018-01-21 09:43:03.937 DEBUG [beaker.container] lock_createfunc (waiting)
2018-01-21 09:43:03.937 DEBUG [beaker.container] lock_createfunc (waited)
2018-01-21 09:43:03.937 DEBUG [beaker.container] get_value creating new value
2018-01-21 09:43:03.937 DEBUG [beaker.container] set_value stored time 1516524183.937 expire time 10
2018-01-21 09:43:03.937 DEBUG [beaker.container] released create lock
2018-01-21 09:43:03.937 DEBUG [kallithea.lib.auth] Auth User lookup by database user None
2018-01-21 09:43:03.937 DEBUG [kallithea.lib.auth] filling <User('id:1:default')> data
2018-01-21 09:43:03.951 DEBUG [kallithea.lib.auth] Auth User is now <AuthUser('id:1[default] auth:True')>
2018-01-21 09:43:03.951 INFO  [kallithea.lib.base] IP: 192.168.124.55 User: <AuthUser('id:1[default] auth:True')> accessed /
2018-01-21 09:43:03.951 DEBUG [pylons.controllers.core] Calling '__before__' method with keyword args: **{}
2018-01-21 09:43:03.967 DEBUG [pylons.controllers.core] Looking for u'index' method to handle the request
2018-01-21 09:43:03.967 DEBUG [pylons.controllers.core] Calling 'index' method with keyword args: **{}
2018-01-21 09:43:03.967 DEBUG [kallithea.lib.auth] Checking access for user <AuthUser('id:1[default] auth:True')> @ HomeController:index
2018-01-21 09:43:03.967 DEBUG [beaker.container] lock_createfunc (waiting)
2018-01-21 09:43:03.967 DEBUG [beaker.container] lock_createfunc (waited)
2018-01-21 09:43:03.967 DEBUG [beaker.container] get_value creating new value
2018-01-21 09:43:03.967 DEBUG [beaker.container] set_value stored time 1516524183.968 expire time 10
2018-01-21 09:43:03.967 DEBUG [beaker.container] released create lock
2018-01-21 09:43:03.967 DEBUG [beaker.container] lock_createfunc (waiting)
2018-01-21 09:43:03.967 DEBUG [beaker.container] lock_createfunc (waited)
2018-01-21 09:43:03.967 DEBUG [beaker.container] get_value creating new value
2018-01-21 09:43:03.983 DEBUG [beaker.container] set_value stored time 1516524183.984 expire time 10
2018-01-21 09:43:03.983 DEBUG [beaker.container] released create lock
2018-01-21 09:43:03.983 DEBUG [kallithea.lib.auth] checking if ip:192.168.124.55 is subnet of set(['0.0.0.0/0', '::/0'])
2018-01-21 09:43:03.983 DEBUG [kallithea.lib.auth] IP 192.168.124.55 is network 0.0.0.0/0
2018-01-21 09:43:03.983 DEBUG [kallithea.lib.auth] IP:192.168.124.55 is in range of set(['0.0.0.0/0', '::/0'])
2018-01-21 09:43:03.983 INFO  [kallithea.lib.auth] user <AuthUser('id:1[default] auth:True')> authenticated with regular auth @ HomeController:index
2018-01-21 09:43:03.983 DEBUG [kallithea.lib.auth] checking cls:HasRepoGroupPermissionAny set(['group.admin', 'group.read', 'group.write']) usr:<AuthUser('id:1[default] auth:True')> group:intern @ RepoGroupList
2018-01-21 09:43:03.983 DEBUG [kallithea.lib.auth] Getting PERMISSION tree
2018-01-21 09:43:04.046 DEBUG [kallithea.lib.auth] Permission to group:intern granted for user: <AuthUser('id:1[default] auth:True')> @ RepoGroupList
2018-01-21 09:43:04.062 DEBUG [kallithea.lib.auth] checking cls:HasPermissionAll set(['hg.admin']) usr:<AuthUser('id:1[default] auth:True')>  @ access admin main page
2018-01-21 09:43:04.062 DEBUG [kallithea.lib.auth] Permission to  denied for user: <AuthUser('id:1[default] auth:True')> @ access admin main page
2018-01-21 09:43:04.062 DEBUG [kallithea.lib.auth] checking cls:HasPermissionAny set(['hg.admin', 'hg.register.auto_activate', 'hg.register.manual_activate']) usr:<AuthUser('id:1[default] auth:True')>  @ unspecified location
2018-01-21 09:43:04.062 DEBUG [kallithea.lib.auth] Permission to  granted for user: <AuthUser('id:1[default] auth:True')> @ unspecified location
2018-01-21 09:43:04.062 DEBUG [pylons.controllers.core] Controller returned a unicode string , writing it to pylons.response
2018-01-21 09:43:04.062 DEBUG [pylons.controllers.core] Calling Response object to return WSGI data
2018-01-21 09:43:04.076 DEBUG [kallithea.SimpleHg] Request time: 1.803s
2018-01-21 09:43:04.076 DEBUG [kallithea.SimpleGit] Request time: 1.803s
2018-01-21 09:43:04.076 INFO  [kallithea.RequestWrapper] IP: 192.168.124.55 Request to / time: 1.803s

When I click one of the links on the Kallithea start page (like Public Journal) nothing gets logged, in the browser I get a 404 error. It seems that only GET requests for the root ( GET / ) work but all others like GET /_admin/public_journal or GET /css/style.css do not.

I dug deeper into IIS logging and found out that requests other than GET / get forwarded to the ISAPI handler _dispatch.dll correcly:

RequestURL
http://hg2.vision.local:80/my_pullrequests 

11.  -HANDLER_CHANGED 
OldHandlerName

NewHandlerName
kallithea 

NewHandlerModules
IsapiModule 

NewHandlerScriptProcessor
C:\inetpub\kallithea\_dispatch.dll 

but since "python -m win32traceutil" does not show any output for these requests I assume that the request does not get forwarded from _dispatch.dll to Kallithea.

So the problem seems to be within _dispatch.dll

Sorry, I had not inspected the screenshot close enough.

In your log, I see that the repository path is set to F:\Kallithea\Repos, while your installation is on C:\. Is it intentional? It shouldn't be a problem though, and in any case, I don't think it could cause the issue you are having now.

When you said that you enabled tracing in IIS, is that 'failed request tracing' as described here: https://docs.microsoft.com/en-us/iis/troubleshoot/using-failed-request-tracing/troubleshooting-failed-requests-using-tracing-in-iis ?

Have you considered re-executing the steps to create the dispatch file, in case something went wrong there? I'm referring to the steps paster install-iis and python2 dispatch.py install.

tracing for GET /

tracing for GET style...

tracing for GET /my_pullrequests

Internet explorer style sheet to format tracing reports correctly

There is nothing to apologize for, I appreciate your quick help!

In your log, I see that the repository path is set to F:\Kallithea\Repos, while your installation is on C:. Is it intentional? It shouldn't be a problem though, and in any case, I don't think it could cause the issue you are having now.

Yes, that path is intentional and works fine when I run Kallithea through paster.

Have you considered re-executing the steps to create the dispatch file, in case something went wrong there? I'm referring to the steps paster install-iis and python2 dispatch.py install.

I have done that.

When you said that you enabled tracing in IIS, is that 'failed request tracing' as described here: https://docs.microsoft.com/en-us/iis/troubleshoot/using-failed-request-tracing/troubleshooting-failed-requests-using-tracing-in-iis ?

That is exactly the instruction I followed to enable the tracing. But I did enable more - all areas for ISAPI as well as WWW are traced.

But I also have to correct my original statement that nothing is logged in IIS. I forgot to enable tracing again, after I created a new test website. I attached some traces I got from the current setup. fr000176.xml is the trace for GET / which shows no errors. the other two show an file not found error ErrorCode (0x80070002) - I guess that happens because the request handler does not return anything!?

In the mean time I migrated the "old" hgweb.cgi website from IIS 6 to the same new IIS 10 server and it is running just fine. It uses the same Python27 installation as Kallithea, so there seems to be nothing wrong with the combination of IIS 10 + Python27 (which is 64bit btw.)

Thanks for the traces. Based on them, it seems that the requests for things other than / do not actually get forwarded to the dispatch handler. It seems they are decided to be 'not present' by an earlier step.

It looks as if IIS is not aware that any path should be forwarded to the dispatcher, not only the root path. From the Kallithea documentation, I read:

This accomplishes two things: generating an ISAPI compliant DLL file, _dispatch.dll, and installing a script map handler into IIS for the --virtualdir specified above pointing to _dispatch.dll.

The ISAPI handler is registered to all file extensions, so it will automatically be the one handling all requests to the specified virtual directory. When the website starts the ISAPI handler, it will start a thread pool managed wrapper around the paster middleware WSGI handler that Kallithea runs within and each HTTP request to the site will be processed through this logic henceforth.

The dispatching relies on isapi-wsgi. Their wiki has some info that may be useful, for example: https://github.com/hexdump42/isapi-wsgi/wiki/Understanding--ISAPI-WSGI

In Kallithea, the file that handles/creates the dispatch file is kallithea/lib/paster_commands/install_iis.py, in case it helps.

Meanwhile I'll also try to read on these pages...

If I compare the install_iis.py script with the example on the mentioned wiki page, things look fine there. Could you paste the contents of the generated dispatch.py file?

Did you use the exact install-iis command as given in the documentation?

paster install-iis my.ini --virtualdir=/

Is there a way to inspect the configuration in the IIS server itself, specifically the configuration of virtual dirs and such?

Following statement on the mentioned wiki caught my attention:

Note that the automatic IIS configuration in step 4 is convenience only. It is possible to configure IIS manually by installing a wildcard handler using the generated DLL file. If you prefer to do this, you can ignore the VirtualDirs list being created below. Do remember to turn off "Check for existence of file" in the IIS configuration.

While such manual installation should not be necessary as this is what the install-iis step is for, the fact that a setting "Check for existence of file" exists is interesting. Could you find out whether it is set or not in your installation?

Was this a fresh installation of IIS or was something configured before? Is it possible that some setting remained from a previous installation? Is it possible to start fresh?

I followed your hints and ran the install procedure again on a clean install and finally got it to work.

The key to make it work was to configure the handler in IIS properly.

The command given in the documentation

paster install-iis my.ini --virtualdir=/

does install a working handler indeed, but only for the IIS default web site. When you follow the instruction and use a new website with root at c:\inetpub\kallithea there is no handler installed for that website. I tried to solve that by manually by installing a wildcard handler, but the problem is that IIS creates a new handler with wrong settings for "request restriction". These default "request restriction" make the handler work for GET / only. You have to deactivate the checkbox at "Invoke handler only if request is mapped to:" and then the Kallithea handler works! I uploaded screenshots of the configuration steps.

Here a summary of what is needed to make Kallithea run under IIS 10:

• IIS needs features "ISAPI Extensions" and "IIS 6 Metabase Compatibility" (needed for isapi_wsgi) installed

• IUSR account needs write access to directory c:\inetpub\kallithea (to be able to write to Kallithea database and data subdirectory)

• IUSR account needs write access to directory where the repositories are stored

• a wildcard handler needs to be setup according to the screenshots

The documentation also mentions

Make sure that there is a unique application pool for the Kallithea application with an identity that has read access to the Kallithea distribution.

IIS 10 creates a unique application pool and application pool identity for each web site by default, but I found it not necessary to grant special privileges to the Kallithea distribution for the application pool identity. It worked fine for me without.

Maybe you can integrate my finding into your instructions and make it easier for others in the future.

You should also mention that running Kallithea on IIS does not work when you install it in a Python virtual environment as described in the Windows installation instructions https://kallithea.readthedocs.io/en/latest/installation_win.html

For IIS Kallthea has to be installed in the default Python environment under C:\Python27

Many thanks for your help!

Now it's time to move on and try out Single-Sign-on...

Great that you found the issue!

Do you think it would be possible for you to update the Kallithea instructions? I think you will be better placed than me to clarify things, as you have the first-hand experience.

If it's not possible, no problem...

Yes, I can do that.