Disconnect (code 2): unexpected service request

Hi there,

It will help if you post the traceback from bzr.log.

I would guess from this that perhaps you need to enable sftp on the server?

Hello!

WinSCP connects to the server with SFTP v3 protocol.

I cannot find bzr.log on Win7. Where is it?

Sorry, here is the log:

H 2010-09-27 09:33:32 +0200
0.063 bzr arguments: [u'version']
0.078 looking for plugins in C:/Documents and Settings/user/Application Data/bazaar/2.0/plugins
0.078 looking for plugins in C:/Program Files/Bazaar/plugins
0.235 encoding stdout as sys.stdout encoding 'cp852'
0.250 return code 0

Mon 2010-09-27 09:34:16 +0200
[ 2004] 2010-09-27 09:34:16.937 INFO: tbzrcache running...

H 2010-09-27 09:34:34 +0200
0.078 bzr arguments: [u'init-repo', u'sftp://username@host/PATH/', u'--v']
0.078 looking for plugins in C:/Documents and Settings/user/Application Data/bazaar/2.0/plugins
0.078 looking for plugins in C:/Program Files/Bazaar/plugins
0.156 encoding stdout as sys.stdout encoding 'cp852'
1.796 falling back to default implementation
1.796 failed to load system host keys: [Errno 2] No such file or directory: 'C:\\Documents and Settings\\user/.ssh/known_hosts'
[ 5700] 2010-09-27 09:34:36.154 INFO: Connected (version 2.0, client 1.82)
2.750 Unable to look up default port for ssh
2.750 encoding stdout as sys.stdout encoding 'cp852'
[ 5700] 2010-09-27 09:34:41.638 INFO: Disconnect (code 2): unexpected service request
7.624 Traceback (most recent call last):
  File "bzrlib\commands.pyo", line 842, in exception_to_return_code
  File "bzrlib\commands.pyo", line 1037, in run_bzr
  File "bzrlib\commands.pyo", line 654, in run_argv_aliases
  File "bzrlib\builtins.pyo", line 1794, in run
  File "bzrlib\transport\__init__.pyo", line 366, in ensure_base
  File "bzrlib\transport\sftp.pyo", line 664, in mkdir
  File "bzrlib\transport\sftp.pyo", line 640, in _mkdir
  File "bzrlib\transport\sftp.pyo", line 399, in _get_sftp
  File "bzrlib\transport\sftp.pyo", line 391, in _create_connection
  File "bzrlib\transport\ssh.pyo", line 325, in connect_sftp
  File "bzrlib\transport\ssh.pyo", line 321, in _connect
  File "bzrlib\transport\ssh.pyo", line 537, in _paramiko_auth
ConnectionError: Connection error: Unable to authenticate to SSH host as
  <email address hidden>
 Authentication failed.

7.624 return code 3

"bzr --version" should tell you where the log file is.

Is there any information in the server's log? Perhaps you can turn on
more information about authentication failures there?

000000000001 2010-09-27 08:09:32.830Z WinSSHD 4.26 [001] Info
  Configuration loaded:
  * Keypair:
  MD5: 9d:77:ba:e4:12:f2:20:52:25:99:b8:4f:61:2f:ff:bc
  Babble: xivak-gurot-dyvog-bynig-byvyb-tazuh-mufyc-fusyp-curib-cenif-cuxox
  * Settings:
  SetDefaults
  server.logging.logFileLevel logLevelEWITD
  With domainOrder {
    Clear
    CreateNewWithId 1
    New.domain "MATRIXONLINE"
    NewCommit
  }
  With access {
    With winAccounts {
      Clear
      CreateNewWithId 1
      With New {
        winDomain "MATRIXONLINE"
        winAccount "Administrator"
        specifyGroup true
        groupType domain
        group "MATRIXONLINE"
        loginAllowed yes
      }
      NewCommit
      CreateNewWithId 2
      With New {
        winDomain "MATRIXONLINE"
        winAccount "imre.laszlo"
        specifyGroup true
        groupType domain
        group "MATRIXONLINE"
        logonType interactive
        sftpRootDir "C:\\Users\\Administrator"
      }
      NewCommit
    }
    virtGroups.Clear
  }

000000000002 2010-09-27 08:09:32.845Z WinSSHD 4.26 [240] Info
  Listening on interface 0.0.0.0:22

000000000003 2010-09-27 08:09:32.845Z WinSSHD 4.26 [005] Info
  Service started, executable file name:
  C:\Program Files (x86)\Bitvise WinSSHD\WinSSHD.exe

000000000004 2010-09-27 08:09:37.564Z WinSSHD 4.26 [021] Info
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Connection from 87.229.83.2:2982 accepted.

000000000005 2010-09-27 08:09:37.580Z WinSSHD 4.26 [190] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Sending version: 5353482D322E302D312E3832207373686C69623A2057696E535348442034
  2E32360D0A

000000000006 2010-09-27 08:09:37.580Z WinSSHD 4.26 [022] Info
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Client version string: SSH-2.0-paramiko_1.7.4

000000000007 2010-09-27 08:09:37.580Z WinSSHD 4.26 [191] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Sending SSH_MSG_KEXINIT (551 bytes, seq nr 0)
  Data: 147855B7AD9BC633BEE3174DFF491368DA000000A86469666669652D68656C6C6D616E2
  D67726F7570312D736861312C6469666669652D68656C6C6D616E2D67726F757031342D736861
  312C6469666669652D68656C6C6D616E2D67726F75702D65786368616E67652D736861312C677
  3732D67726F7570312D736861312D746F574D35536C77354577384D716B61792B616C32673D3D
  2C6773732D6765782D736861312D746F574D35536C77354577384D716B61792B616C32673D3D0
  00000077373682D647373000000696165733235362D6362632C74776F666973683235362D6362
  632C74776F666973682D6362632C6165733132382D6362632C74776F666973683132382D63626
  32C626C6F77666973682D6362632C336465732D6362632C617263666F75722C63617374313238
  2D636263000000696165733235362D6362632C74776F666973683235362D6362632C74776F666
  973682D6362632C6165733132382D6362632C74776F666973683132382D6362632C626C6F7766
  6973682D6362632C336465732D6362632C617263666F75722C636173743132382D63626300000
  02B686D61632D736861312C686D61632D6D64352C686D61632D736861312D39362C686D61632D
  6D64352D39360000002B686D61632D736861312C686D61632D6D64352C686D61632D736861312
  D39362C686D61632D6D64352D3936000000097A6C69622C6E6F6E65000000097A6C69622C6E6F
  6E6500000000000000000000000000

000000000008 2010-09-27 08:09:37.580Z WinSSHD 4.26 [152] Trace
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Starting first key exchange

000000000009 2010-09-27 08:09:37.626Z WinSSHD 4.26 [193] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Received SSH_MSG_KEXINIT (318 bytes, seq nr 0)
  Data: 14D7068C583FCBDBB96027526BC1ED30970000003D6469666669652D68656C6C6D616E2
  D67726F7570312D736861312C6469666669652D68656C6C6D616E2D67726F75702D6578636861
  6E67652D736861310000000F7373682D7273612C7373682D6473730000002B6165733132382D6
  362632C626C6F77666973682D6362632C6165733235362D6362632C336465732D636263000000
  2B6165733132382D6362632C626C6F77666973682D6362632C6165733235362D6362632C33646
  5732D6362630000002B686D61632D736861312C686D61632D6D64352C686D61632D736861312D
  39362C686D61632D6D64352D39360000002B686D61632D736861312C686D61632D6D64352C686
  D61632D736861312D39362C686D61632D6D64352D3936000000046E6F6E65000000046E6F6E65
  00000000000000000000000000

000000000010 2010-09-27 08:09:37.626Z WinSSHD 4.26 [196] Trace
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Will act on first key exchange method packet

000000000011 2010-09-27 08:09:37.861Z WinSSHD 4.26 [193] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Received SSH_MSG_KEX_30 (134 bytes, seq nr 1)
  Data: 1E0000008100B38A31E862C2A83E53002DDD2341D3435D704A56F98554965A0EAFA176E
  0458B6EFCFBF825492138CF37C6269669AD8DB15C17072C3A8ADADB1A921F34FCBED5577A2A6E
  810A3B24754FFC1F32C89A015849ED82E7901A6882B95F792EC84E5CF558424962F81B565C99A
  507361DD4115F21653B990B95B180D78CD4F7F3775A

000000000012 2010-09-27 08:09:37.861Z WinSSHD 4.26 [191] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Sending SSH_MSG_KEX_31 (631 bytes, seq nr 1)
  Data: 1F000001B3000000077373682D6473730000008100F97A0BF4EACC742B29EC641F6D575
  9601C8E0AC19933399B2B2E71FD2F4419E227EB622BEEE4625F9336EBD588760E21295D5E9282
  61014468D06DD1CB64E22DBA32CF2D674027168FC4F89C72E4FC62266E934D3A1908D3799F9D9
  3D60A1FB2B1A7823651ABB1280A1A066B807F849F4D10EB1FA4C37106D900EB365F4535690000
  001500D2ECBF3417C253865496B69BCD903C1A8EB08ABD00000081008079F9C15B1A58E959D3C
  A9B746676AC6FD1F34D80393A7CB2952EE86CA6C6C2BE1A481A1C4AE47B4054B4E7EA1ACF9635
  0D61D8C46757579C09F8CDADB9DA6745D3AE554001044249DC63F5E768D4C77173CCC756832F0
  4C071AAD460B44F9C80735BDECE24AF8E2D9994C07A61F499F73F0AAB8ED4B8A5B470D720006A
  40C900000081008C15C08A2ADABE1CE529EB09A37189B935DE65E7C76889568588B3A0C61ACDD
  712B838E50BE2A6E2A6A0B801110315471D6A17AEA851D9677A8D2327C00C75446EE7D8F56660
  D67B182ED032266075483295C9F558BE826214FC510804B7B594069A1177949C9B0E6DE849B6E
  7DCCD0D3D3FF50A9EF86D967C366B8EF34123B60000008076A4C54D7DB05F7B52531D588A5D8E
  9B450781DA72BE8511BFA5C9B531137EAEFE0B9E3FE94B7295351D72B8D019A6C0A08D293ED9D
  F8C8767B3678B6FDD7C4BA52194D148A12051AF59B0EBEEED09AA6ABA0E3D0A73EA999D1D7154
  99072CF2D4D5B2E5F5387620A74048FFA51ABCC3D8410927C07558F0EC5B8D41E68597B100000
  037000000077373682D64737300000028C169C94F928D832C987F75F7DD4DD2DDFAEFC496A476
  D8A31AF8AC461AEBD69C9428906BC57A8BE8

000000000013 2010-09-27 08:09:37.861Z WinSSHD 4.26 [191] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Sending SSH_MSG_NEWKEYS (1 bytes, seq nr 2)
  Data: 15

000000000014 2010-09-27 08:09:37.861Z WinSSHD 4.26 [152] Trace
  Session thread 1001 handling connection from 87.229.83.2:2982:
  First key exchange completed

000000000015 2010-09-27 08:09:37.861Z WinSSHD 4.26 [255] Trace
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Key exchange: diffie-hellman-group1-sha1. Session encryption: aes128-cbc,
  MAC: hmac-sha1, compression: none.

000000000016 2010-09-27 08:09:37.939Z WinSSHD 4.26 [193] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Received SSH_MSG_NEWKEYS (1 bytes, seq nr 2)
  Data: 15

000000000017 2010-09-27 08:09:38.220Z WinSSHD 4.26 [193] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Received SSH_MSG_SERVICE_REQUEST (17 bytes, seq nr 3)
  Data: 050000000C7373682D7573657261757468

000000000018 2010-09-27 08:09:38.220Z WinSSHD 4.26 [252] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Handling SSH_MSG_SERVICE_REQUEST for 'ssh-userauth'

000000000019 2010-09-27 08:09:38.220Z WinSSHD 4.26 [191] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Sending SSH_MSG_SERVICE_ACCEPT (17 bytes, seq nr 3)
  Data: 060000000C7373682D7573657261757468

000000000020 2010-09-27 08:09:38.251Z WinSSHD 4.26 [193] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Received SSH_MSG_USERAUTH_REQUEST (42 bytes, seq nr 4)
  Data: 320000000B696D72652E6C61737A6C6F0000000E7373682D636F6E6E656374696F6E000
  000046E6F6E65

000000000021 2010-09-27 08:09:38.251Z WinSSHD 4.26 [252] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Entering ServerAuthenticator::ProcessUserAuthPacket()

000000000022 2010-09-27 08:09:38.251Z WinSSHD 4.26 [252] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Handling SSH_MSG_USERAUTH_REQUEST for user 'imre.laszlo', service
  'ssh-connection', method 'none'

000000000023 2010-09-27 08:09:38.251Z WinSSHD 4.26 [252] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Calling OnUserAuthMethodStart()

000000000024 2010-09-27 08:09:38.251Z WinSSHD 4.26 [252] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Authentication method is disabled

000000000025 2010-09-27 08:09:38.251Z WinSSHD 4.26 [252] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  In SendUserAuthFailure()

000000000026 2010-09-27 08:09:38.251Z WinSSHD 4.26 [191] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Sending SSH_MSG_USERAUTH_FAILURE (40 bytes, seq nr 4)
  Data: 33000000227075626C69636B65792C6773736170692D776974682D6D69632C706173737
  76F726400

000000000027 2010-09-27 08:09:38.251Z WinSSHD 4.26 [252] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Calling OnUserAuthMethodEnd()

000000000028 2010-09-27 08:09:38.251Z WinSSHD 4.26 [252] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Exiting ServerAuthenticator::ProcessUserAuthPacket()

000000000029 2010-09-27 08:09:41.845Z WinSSHD 4.26 [193] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Received SSH_MSG_SERVICE_REQUEST (17 bytes, seq nr 5)
  Data: 050000000C7373682D7573657261757468

000000000030 2010-09-27 08:09:41.845Z WinSSHD 4.26 [191] Dump
  Session thread 1001 handling connection from 87.229.83.2:2982:
  Sending SSH_MSG_DISCONNECT (41 bytes, seq nr 5)
  Data: 01000000020000001A756E6578706563746564207365727669636520726571756573740
  0000002656E

000000000031 2010-09-27 08:09:41.876Z WinSSHD 4.26 [094] Warning
  Session thread 1001 handling connection from 87.229.83.2:2982:
  The client has been disconnected, we sent the following disconnect reason:
  SSH_DISCONNECT_PROTOCOL_ERROR, description: unexpected service request

000000000032 2010-09-27 08:09:45.017Z WinSSHD 4.26 [006] Info
  Service stopped.

Maybe this can help: https://fogbugz.bitvise.com/default.asp?WinSSHD.1.2828.3