- changed status to open
-
assigned issue to
Authorization failure while trying to clone a Hg repo
Hi,
First let me appreciate this great tool. It's simple and elegant.
My problem is, I'm getting authorization failure while trying to use SCM-Manager with TrotoiseHg.
Here is the sequence what I'm doing.
- Unzipping the scm-manager 1.16 to "C:\Program Files\scm-server" directory. (Already disabled UAC for potential issues).
- Installing Mercurial 2.2.2 to "Program Files" via Innosetup installer. (Checked, hg.exe is accessible from everywhere.)
- Installing Python 2.7.3 to "Program Files\Python27".
- Runing scm-manager server via double clicking "\bin\scm-server.bat"
- In a command line window scm-server starts working.
- Checking with another command line "netstat -an". scm-server is listening 8080 port.
- Opening browser entering localhost:8080. Great works.
- Entering default creditentials, works.
- Clicking Repository Types, setting up the Mercurial. Saving.
- Creating some users, works...
- Creating a test repo with Mercurial. OK.
- Checking Repository directory if it actually exists. Yes, it's there.
- Local Clone with mercurial. Works, great, a real Hg repo.
- Trying to Clone via http interface.
- Using TortoiseHg to clone. Asks for username. Entering it as "muratursavas"
- Asks for the password. Entering the password, which works for the SCM-Manager's own interface.
- Out of luck. TortoiseHg Says (In fact, SCM-Manager says): % hg clone --verbose -- h..p://192.168..**:8080/scm/hg/FooProject http authorization required realm: SONIA :: SCM Manager abort: authorization failed [command returned code 255 Wed Jun 27 10:17:44 2012]
Most probably it is a very simple issue but my humble brain haven't found any solution yet.
The log does not show anything about the authorization rejection. Background trace show no sign of accessing to Hg.exe. Clearly something goes wrong before accessing python or hg exes.
I even tried to make the repo public, but it didn't help either. It asks for creditentials (I don't know why) and fails after entering it.
The machine is Windows 7 x86, a fresh install on vmware. Software versions:
SCM-Manager (1.16) Java (1.6.0.33) Mercurial (2.2.2) Pyhton (2.7.3) Firefox (13.0.1) TortoiseHg (2.4.1)
Thanks in advance.
/// Murat
Comments (45)
-
-
- attached Procmon Logfile.CSV
Hi Sebastion,
I tried what you've suggested and installed the Mercurial 2.1 & Python 2.6 package. Even removed the old installations and restarted to clear PATH variable. Unfortunately it didn't work.
SCM-Server haven't even try to reach python or mercurial. You can see the Procmon log attached. There is no attempt to call that processes. Just socket requests and responses.
Where do you keep the user creditentials? If it's not in the memory, java.exe should access that location and I have to see it.
You know, the command line window which runs the scm-server.bat file, shows every activity. But I can not see anything about this failed authorization. Is this normal? Log file does not show anything either.
Thanks, Regards.
-
Please enable trace logging (https://bitbucket.org/sdorra/scm-manager/wiki/faq) and post the output of the log. Before you post the log, remove lines like the following:
- HTTP_AUTHORIZATION=Basic xxxxxx
-
- attached scm-manager.log
Please find attached log. It was already set up for trace. As I said before, I looked in to log before trying to clone, and checked after the failure, nothing was changed.
(I cleared the old enntries before opening scm-server.bat)
-
I could not see any request in the log. Please try to open scm-manager with a browser. Did you see the browser request in the log? Could you post this "C:\Users\Administrator\.scm\config\hg.xml" file?
-
- attached hg.xml
Here is the added part to the log after login via Web Interface.
13:00:04.977 [qtp32077430-20] DEBUG sonia.scm.web.security.DefaultAuthenticationHandler - user scmadmin successfully prepared for login 13:00:04.980 [qtp32077430-20] DEBUG sonia.scm.web.security.ChainAuthenticatonManager - authenticator sonia.scm.web.security.DefaultAuthenticationHandler ends with result, user: scmadmin, state: SUCCESS 13:00:04.983 [qtp32077430-20] DEBUG sonia.scm.web.security.BasicSecurityContext - authenticator xml marked user scmadmin as admin 13:00:04.983 [qtp32077430-20] DEBUG sonia.scm.web.security.BasicSecurityContext - user scmadmin of type xml is marked as admin by local database 13:00:04.987 [qtp32077430-20] DEBUG sonia.scm.web.security.BasicSecurityContext - user scmadmin is not a member of a group 13:00:05.803 [qtp32077430-21] DEBUG sonia.scm.repository.AbstractRepositoryManager - register POST_RECEIVE hook class sonia.scm.repository.ChangesetViewerUtil 13:00:05.813 [qtp32077430-21] DEBUG sonia.scm.repository.AbstractRepositoryManager - register POST_RECEIVE hook class sonia.scm.repository.RepositoryBrowserUtil 13:00:05.814 [qtp32077430-21] DEBUG sonia.scm.repository.AbstractRepositoryManager - register POST_RECEIVE hook class sonia.scm.repository.BlameViewerUtil
After that I tried to clone via directly calling "hg clone http://localhost:8080/scm/hg/fooProject" and authorization failed again. And nothing show up in the command line window and log.
Please find the hg.xml attachment.
-
If the log does not change, then there is no request to the repository. You should see at least a line like the following:
DEBUG sonia.scm.web.security.ChainAuthenticatonManager - authenticator sonia.scm.web.security.DefaultAuthenticationHandler ends with result, ...
Have you some special configurations in your hgrc? Or could you try to clone the repository with your hostname or ipaddress instead of localhost (e.g. http://myserver:8080/scm/hg/fooProject)?
-
I don't have anything special in hgrc. Here you can find it:
[web] push_ssl = false allow_read = * allow_push = * [hooks] changegroup.scm = python:scmhooks.callback pretxnchangegroup.scm = python:scmhooks.callback
I tried your suggestion with server name, Ethernet IP address, both failed. I tried 128.0.0.1, and got "machine actively refuses it" error message.
Also I made the FooProject public in the settings, but clone request still asks for authorization. Isn't that a bit weird?
Only suspicious thing in log file:
13:56:51.197 [qtp32077430-19] INFO sonia.scm.repository.DefaultRepositoryManager - modify repository FooProject of type hg 13:56:51.244 [qtp32077430-19] TRACE sonia.scm.group.xml.XmlGroupDAO - modify xml backend item 209409cd-89ad-4454-93a0-9bad97d2beca 13:56:51.259 [qtp32077430-19] TRACE sonia.scm.group.xml.XmlGroupDAO - store xml database 13:56:51.259 [qtp32077430-19] DEBUG sonia.scm.store.JAXBStore - store sonia.scm.repository.xml.XmlRepositoryDatabase to C:\Users\Administrator\.scm\config\repositories.xml 13:56:54.822 [qtp32077430-18] INFO sonia.scm.repository.DefaultRepositoryManager - modify repository FooProject of type hg 13:56:54.822 [qtp32077430-18] TRACE sonia.scm.group.xml.XmlGroupDAO - modify xml backend item 209409cd-89ad-4454-93a0-9bad97d2beca 13:56:54.822 [qtp32077430-18] TRACE sonia.scm.group.xml.XmlGroupDAO - store xml database 13:56:54.822 [qtp32077430-18] DEBUG sonia.scm.store.JAXBStore - store sonia.scm.repository.xml.XmlRepositoryDatabase to C:\Users\Administrator\.scm\config\repositories.xml 13:56:57.853 [qtp32077430-15] WARN sonia.scm.cache.EhCacheManager - could not find cache sonia.scm.hg.packages, create new from defaults 13:58:28.900 [qtp32077430-19] INFO sonia.scm.repository.DefaultRepositoryManager - modify repository FooProject of type hg 13:58:28.900 [qtp32077430-19] TRACE sonia.scm.group.xml.XmlGroupDAO - modify xml backend item 209409cd-89ad-4454-93a0-9bad97d2beca 13:58:28.900 [qtp32077430-19] TRACE sonia.scm.group.xml.XmlGroupDAO - store xml database 13:58:28.900 [qtp32077430-19] DEBUG sonia.scm.store.JAXBStore - store sonia.scm.repository.xml.XmlRepositoryDatabase to C:\Users\Administrator\.scm\config\repositories.xml
There is a warning at 13:56:57.853. Could it be something related to this issue?
-
No the warning, is not related to this issue. 128.0.0.1 is this correct or did you 127.0.0.1 localhost ip? For public access you have to enable "Allow Anonymous Access" at Config->General. Could you post the output of the "hg clone --verbose --debug http://..."?
-
You're right, I accidentaly wrote 128.0.0.1. Checked with 127.0.0.1 given the same result with localhost.
Here is the output of hg clone.
C:\Users\KMT\Desktop>hg clone --verbose --debug http://192.168.2.245:8080/scm/hg/FooProject using http://192.168.2.245:8080/scm/hg/FooProject sending capabilities command http authorization required realm: SONIA :: SCM Manager user: muratursavas password: http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** abort: authorization failed
I tried enabling public access and it worked. But I still can't access non-public ones.
-
Please use --debug and --verbose.
-
This is very strange, it looks like wrong password. Could you please check the auth section of your hgrc in your home directory.
-
Has user muratursavas the permissions to read the FooProject repository?
-
muratursavas has the rights to READ. In fact I tried it for also WRITE and OWNER. Nothing changed. I changed my password to 123456 to eliminate another parameter but it didn't help. I even used another keyboard for typos :)
I don't have any hgrc file in my home directory (which is C:\Users\Administrator) but I have in repositories .hg directory. Which has no [auth] section.
[After trying something ...]
I think I found a clue. Right now FooProject is not public and hg clone produces the following output:
C:\Users\KMT\Desktop>hg clone --verbose --debug http://muratursavas@192.168.2.245:8080/scm/hg/FooProject using http://192.168.2.245:8080/scm/hg/FooProject http auth: user muratursavas, password not set sending capabilities command http authorization required realm: SONIA :: SCM Manager user: muratursavas password: http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** abort: authorization failed
This operation now creates traces in log. Here it is:
16:40:00.148 [qtp32077430-21] WARN sonia.scm.web.filter.PermissionFilter - user anonymous has not enough permissions 16:40:17.941 [qtp32077430-21] WARN sonia.scm.web.filter.PermissionFilter - user anonymous has not enough permissions 16:40:17.941 [qtp32077430-16] WARN sonia.scm.web.filter.PermissionFilter - user anonymous has not enough permissions 16:40:17.957 [qtp32077430-17] WARN sonia.scm.web.filter.PermissionFilter - user anonymous has not enough permissions 16:40:17.957 [qtp32077430-18] WARN sonia.scm.web.filter.PermissionFilter - user anonymous has not enough permissions 16:40:17.957 [qtp32077430-19] WARN sonia.scm.web.filter.PermissionFilter - user anonymous has not enough permissions 16:40:17.972 [qtp32077430-20] WARN sonia.scm.web.filter.PermissionFilter - user anonymous has not enough permissions
I'm not sending anonymous as the username but somehow scm-server takes it so.
-
To clarify it is a version problem or not, I used the mercurial which is provided by the downloaded library. Here is the output:
C:\Users\Administrator\.scm\pkg\f1ea71\hg\2.1\bin>hg.bat clone --verbose --debug http://muratursavas@localhost:8080/scm/hg/FooProject using http://localhost:8080/scm/hg/FooProject http auth: user muratursavas, password not set sending capabilities command http authorization required realm: SONIA :: SCM Manager user: muratursavas password: http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** http auth: user muratursavas, password ****** abort: authorization failed
And it created the same anonymous warning traces.
-
Please disable the "Allow Anonymous Access" and try to use the administrator (scmadmin).
-
Anonymous access disabled. used scmadmin as user.
Output:
C:\Users\Administrator\.scm\pkg\f1ea71\hg\2.1\bin>hg.bat clone --verbose --debug http://scmadmin@localhost:8080/scm/hg/FooProject using http://localhost:8080/scm/hg/FooProject http auth: user scmadmin, password not set sending capabilities command http authorization required realm: SONIA :: SCM Manager user: scmadmin password: http auth: user scmadmin, password ******** http auth: user scmadmin, password ******** http auth: user scmadmin, password ******** http auth: user scmadmin, password ******** http auth: user scmadmin, password ******** http auth: user scmadmin, password ******** abort: authorization failed
No traces found after this command. (Both command line window of scm-server and log file checked)
-
This is really strange, i've never seen a error like this one. Could you test svn or git access?
-
OK Sebastian, I'll install git tomorrow and check the result. I don't have access to this server at the evenings. I even will check the outgoing and incoming TCP packets to verify the username and password. (I don't know if I'll be able to see password since it might be hashed)
Thanks for your honest support. If I can use SCM-Manager properly, we'll start to use it in our company with Mercurial (and maybe with also SVN)
-
Good Morning,
I just checked wth GIT and SVN , unfortunately failed like Mercurial.
Here is the output for git:
C:\Users\Administrator\Desktop>git clone http://scmadmin@192.168.2.245:8080/scm/git/FooGit Cloning into 'FooGit'... Password for 'http://scmadmin@192.168.2.245:8080': fatal: Authentication failed
Also I tried SVN, it failed, too.
C:\Users\Administrator\Desktop>svn checkout http://scmadmin@192.168.2.245:8080/scm/svn/FooSvn Authentication realm: <http://192.168.2.245:8080> SONIA :: SCM Manager Password for 'Administrator': ******** Authentication realm: <http://192.168.2.245:8080> SONIA :: SCM Manager Username: scmadmin Password for 'scmadmin': ******** Authentication realm: <http://192.168.2.245:8080> SONIA :: SCM Manager Username: scmadmin Password for 'scmadmin': ******** svn: E170001: Unable to connect to a repository at URL 'http://scmadmin@192.168.2.245:8080/scm/svn/FooSvn' svn: E170001: OPTIONS of 'http://scmadmin@192.168.2.245:8080/scm/svn/FooSvn': authorization failed: Could not authenticate to server: rejected Basic challenge (http://192.168.2.245:8080)
Why scm-server tries "Administrator" user first? Shouldn't it be "scmadmin"? Could it be something about ActiveDirectory-ish issue? Anyway, as you can see I tried agaiin for scmadmin, failed.
All of projects have the correct user rights for scmadmin.
[git version 1.7.10.msysgit.1]
[svn version 1.7.5 (r1336830)]
-
The try with comes from svn and not from scm-manager. Svn uses always the os user for the first login. Have you installed the activedirectory plugin?
-
Nope, it's plain install. I just downloaded the mercurial/python install with your suggestion. That's all.
-
Could you try the following:
- Close your browser (to clear all scm-manager sessions)
- reopen your browser and open directly the url of a project http://localhost:8080/scm/hg/FooProject
- try to login with the basic authentication
-
Before that, I checked the transmission. You might want to check it out.
Here is the request for clone:
GET /scm/hg/FooProject?cmd=capabilities HTTP/1.1\r\n Accept-Encoding: identity\r\n host: 192.168.2.245:8080\r\n accept: application/mercurial-0.1\r\n user-agent: mercurial/proto-1.0\r\n \r\n Full request URI: http://192.168.2.245:8080/scm/hg/FooProject?cmd=capabilities
Here is the attempt for authenticatiion (sent by client to server):
GET /scm/hg/FooProject?cmd=capabilities HTTP/1.1\r\n Accept-Encoding: identity\r\n host: 192.168.2.245:8080\r\n authorization: Basic c2NtYWRtaW46c2NtYWRtaW4=\r\n accept: application/mercurial-0.1\r\n user-agent: mercurial/proto-1.0\r\n \r\n Full request urı: http://192.168.2.245:8080/scm/hg/FooProject?cmd=capabilities
To go even deep I tried to convert authorization value from BASE64 to HEX and cross checked with the stored scmadmin password (in users.xml file). Couldn't find any pattern.
But I saw that authorization is straight forward, uses symmetric cipher. same username password creates same authorization string.
-
I tried your suggestion (comment 23).
Same problem. Haven't authorized.
Firefox result:
HTTP ERROR 401 Problem accessing /scm/hg/FooProject. Reason: Authorization Required Powered by Jetty://
-
Could you test the basic auth from another client?
-
On same server:
- Internet Explorer 8 (Negative)
- Firefox (Negative)
On another computer:
- Chrome (Negative)
- Firefox (Negative)
- Internet Explorer 9 (32bit) (Negative)
- Internet Explorer 9 (64bit) (Negative)
-
Is there a way to expose scm-server's internal authorization mechanism? We might find a clue in there?
Like why the passwords or usernames couldn't match, because of the incoming one or the stored one? Or maybe it's just a unexpected string coming from nowhere.
-
Could please do the following steps:
- stop scm-manger
- move the scm home directory
- start scm-manager
- login as admin
- create a new svn repository
- try to checkout the new repository from svn command line
If this does not work, i will provide a new version with more logging to find the problem.
-
Unfortunatley it haven't helped.
C:\>svn checkout http://scmadmin@192.168.2.245:8080/scm/svn/FooSVN2 Authentication realm: <http://192.168.2.245:8080> SONIA :: SCM Manager Password for 'Administrator': ******** Authentication realm: <http://192.168.2.245:8080> SONIA :: SCM Manager Username: scmadmin Password for 'scmadmin': ******** Authentication realm: <http://192.168.2.245:8080> SONIA :: SCM Manager Username: scmadmin Password for 'scmadmin': ******** svn: E170001: Unable to connect to a repository at URL 'http://scmadmin@192.168.2.245:8080/scm/svn/FooSVN2' svn: E170001: OPTIONS of 'http://scmadmin@192.168.2.245:8080/scm/svn/FooSVN2': authorization failed: Could not authenticate to server: rejected Basic challenge (http://192.168.2.245:8080)
Also tried basic authentication via browser, same failure.
-
I also checked with an XP machine to rule out the OS version parameter. It also has the same authorization issues. I think it's time to check internal authorization mechanism with more logs.
-
Sebastian,
While you're working on the new version, I wanted to use a repo public. I successfuly cloned the repo but could'n push the changes. Is it possible to push anonymously (public)?
-
Ok, i've create a version with more log informations. Please use this version with a fresh .scm directory (move or delete the old one):
- Enable trace logging
- start scm-manager
- open the browser, goto the user interface
- login with scmadmin, scmadmin
- create a svn repository
- logout
- open the new repository in you browser
- try to login with scmadmin, scmadmin
- post the complete log file
Version with improved trace logging:
-
Yes, you can push anonymously. You have to grant write permissions for the user anonymous.
-
- attached scm-manager.log
Here, you can find the log attached.
You might want to add log for "which user is not found" and why. Maybe it's case is not matching, maybe there are some unintenntional characters etc. It would be good to see the user name input (maybe also the password).
As far as I can see you're keeping the XML database in the memory, because at the authorization moment java does not access the xml database. It might be good to trace that memory footprint. It could be reinitialised and resetted unintentially.
-
I've created a new version which prints the complete http request and response. Could you do the same steps from comment 33 with this new version:
-
- attached scm-manager.7z
Please find the log attached (compressed with 7z).
-
I'm really confused! Here we see an authentication, with correct username and password:
sonia.scm.web.filter.LoggingFilter - **************** request **************** sonia.scm.web.filter.LoggingFilter - Header: Authorization = Basic c2NtYWRtaW46c2NtYWRtaW4=
But the BasicAuthenticationFilter logs that he could not find the user. But the filter does not log other messages and this is only possible if no Authorization could be found and no other user is authenticated. Have a look at the doFilter method of the BasicAuthenticationFilter.
sonia.scm.web.filter.BasicAuthenticationFilter - could not find user send unauthorized
Because the basic auth header could not be found, scm-manager returns status code 401 authorization required.
sonia.scm.web.filter.LoggingFilter - **************** response **************** sonia.scm.web.filter.LoggingFilter - status code = 401 sonia.scm.web.filter.LoggingFilter - status message = Authorization Required
Are you familiarly with java and the java debugger?
-
I'm not. My expertise covers lots of languages and platforms, including embedded development, but not java, sorry :)
But I have colleagues capable doing it. Please tell me the right direction to go (correct toolchain, source organization etc) and I'll try to debug it with my friends (or myself. Maybe it's time to dig in java).
-
I think the suspect is this line:
if (Util.isNotEmpty(authentication) && authentication.toUpperCase().startsWith(AUTHORIZATION_BASIC_PREFIX))
One of them is not OK with direct access to repo. Therefore user is never tried to authorized and therefore returns null (There is no log trace like this: "found basic authorization header, start authentication"). But if we access system from the main interface, I think "securityContext.isAuthenticated()" returns true, therefore it gives the system a chance to survive with web UI but not with direct access.
Do you have another authorization for securityContext instance? It could be the solution (or we can debug Util emptiness and authentication string. It might not start with "BASIC", maybe with " BASIC". Left trimming might help?)
-
I think the best solution is to use the debugger to find out what is going wrong. Ok, now it is getting complicated:
- Use the version provided with comment 36
- Be sure you have installed the Oracle Java JDK not only the JRE
- edit the scm-server.bat, search for the following line:
set EXTRA_JVM_ARGUMENTS=-Dlogback.configurationFile=logging.xml -Dscm.debug.http=true
- replace the line with the following:
set EXTRA_JVM_ARGUMENTS=-Dlogback.configurationFile=logging.xml -Xdebug -Xrunjdwp:transport=dt_socket,address=8000,server=y,suspend=n
- start scm-server
- open a page which requires basic authentication, but don't insert the username and password
- start the command line tool jdb from the jdk:
jdb -attach 8000
- set the breakpoint:
stop at sonia.scm.web.filter.BasicAuthenticationFilter:123
- no go back to you browser and insert username and password
- the debugger should now at line 123 of BasicAuthenticationFilter
- please post the output of the following commands:
print authentication print securityContext.isAuthenticated() print securityContext.getUser()
- After you finished insert the run command and exit the debugger with Ctrl+c
-
I think I found the solution without debugging :) (I was doing something else when it was flashed)
I was right, the guilty part of the code is:
authentication.toUpperCase().startsWith(AUTHORIZATION_BASIC_PREFIX)
This is always false for Turkish. That's right, problem is you assume that toUpperCase method will result Basic -> BASIC but in Turkish, it results as BASİC (you see the small point on I :). This causes always false.
I checked it with changing all regional parameters to en-US. Than everything changed. I got different errors about SVN options:
C:\Users\Administrator\Desktop>svn checkout http://scmadmin@localhost:8080/scm/svn/TestSVN svn: E175002: Unable to connect to a repository at URL 'http://scmadmin@localhost:8080/scm/svn/TestSVN' svn: E175002: OPTIONS of 'http://scmadmin@localhost:8080/scm/svn/TestSVN': Could not read response body: connection was closed by server (http://localhost:8080)
As you can see, I'm authorized but SVN whines about something else.
You should use
authentication.toUpperCase(Locale("en-US")).startsWith(AUTHORIZATION_BASIC_PREFIX)
That will convert "Basic" or "basic" to "BASIC". In fact, you should do that for every check string. It will solve the problems with also other languages.
P.S: You might want to check Locale thingy, since I'm not expert on Java.
-
Possible fix 6ea50cd5b739.
Could you please test the version below:
-
Well done Sebastian. It's running with Mercurial 2.2.2 and Python 2.7.3 (which are manually installed by me)
Here is the output:
C:\>hg clone --verbose --debug http://scmadmin@localhost:8080/scm/hg/TestHg using http://localhost:8080/scm/hg/TestHg http auth: user scmadmin, password not set sending capabilities command http authorization required realm: SONIA :: SCM Manager user: scmadmin password: http auth: user scmadmin, password ******** destination directory: TestHg query 1; heads sending batch command http auth: user scmadmin, password ******** no changes found sending listkeys command http auth: user scmadmin, password ******** sending listkeys command http auth: user scmadmin, password ******** updating to branch default resolving manifests overwrite: False, partial: False ancestor: 000000000000, local: 000000000000+, remote: 000000000000 0 files updated, 0 files merged, 0 files removed, 0 files unresolved
The problem was our language, let me thank you in Turkish.
"Eline sağlık" :)
-
- changed status to resolved
- Log in to comment
I think the problem is the Mercurial/Pyhton setup and not the authentication. Mercurial on Windows is very complicated. Could you please try one of the packages provided by the mercurial configuration wizzard (Config->Repository Types->Start Configuration Wizzard->Download and Install)?