Push issue for SMB - Unable to write data to the transport connection (The handshake failed due to an unexpected packet format)

[Outek]

What You Are Seeing?

Choco push don't work on our local Nuget Server

What is Expected?

Push a new package to the Nuget Server

How Did You Get This To Happen? (Steps to Reproduce)

push choco <packagename.nupkg> --api-key= -Source

Additional Information

In the Debug output i saw this line:

Information.PlatformVersion='6.2.9200.0'|
Information.PlatformName='Windows Server 2012'|
Information.ChocolateyVersion='0.10.5.0'|
Information.ChocolateyProductVersion='0.10.5'

I don't know where this Information is coming from... Both, Server and Client, are 2016 Server.
PS C:\Temp\splunk> [environment]::OSVersion.Version

Major Minor Build Revision

---

10 0 14393 0

Attempting to push <packagename>.nupkg to https://<servername:Port>/api/v2/package
Chocolatey had an error occur:
System.IO.IOException: Unable to write data to the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.So
ckets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.Send(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at System.Net.Sockets.NetworkStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.Security._SslStream.StartWriting(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.Security._SslStream.ProcessWrite(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.TlsStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.ConnectStream.InternalWrite(Boolean async, Byte[] buffer, Int32 offset, Int32 size, AsyncCallback callback, Object state)
   at System.Net.ConnectStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.IO.Stream.InternalCopyTo(Stream destination, Int32 bufferSize)
   at NuGet.MultipartWebRequest.CreateMultipartRequest(WebRequest request)
   at System.EventHandler`1.Invoke(Object sender, TEventArgs e)
   at NuGet.RequestHelper.GetResponse()
   at NuGet.PackageServer.EnsureSuccessfulResponse(HttpClient client, Nullable`1 expectedStatusCode)
   at NuGet.PackageServer.PushPackageToServer(String apiKey, Func`1 packageStreamFactory, Int64 packageSize, Int32 timeout, Boolean disableBuffering)
   at chocolatey.infrastructure.app.nuget.NugetPush.push_package(ChocolateyConfiguration config, String nupkgFilePath)
   at chocolatey.infrastructure.app.services.NugetService.push_run(ChocolateyConfiguration config)
   at chocolatey.infrastructure.app.services.ChocolateyPackageService.push_run(ChocolateyConfiguration config)
   at chocolatey.infrastructure.app.runners.GenericRunner.run(ChocolateyConfiguration config, Container container, Boolean isConsole, Action`1 parseArgs)
   at chocolatey.infrastructure.app.runners.ConsoleApplication.run(String[] args, ChocolateyConfiguration config, Container container)
   at chocolatey.console.Program.Main(String[] args)

[ferventcoder]

Use Fiddler and look at the traffic - if we determine it is an issue with Chocolatey - we can fix it. 9/10 it is an issue in the configuration that has been setup - we'd love to help but we will need quite a few more details

[ferventcoder]

That starts with the entire output log as requested - scrub it some but don't only include parts.

[ferventcoder]

Interesting - could you file the issue about the wrong server info separately so we can handle that issue as well?

[Outek]

Yes of course. I'll fill a new issue for the version.

[Outek]

fiddler:
HTTP/1.1 200 Connection Established
FiddlerGateway: Direct
StartTime: 22:38:38.579
Connection: close

fiddler.network.https> HTTPS handshake to servername (for #5) failed. System.IO.IOException The handshake failed due to an unexpected packet format.

Chocolatey v0.10.5
Chocolatey is running on Windows v 6.2.9200.0
Attempting to delete file "C:/ProgramData/chocolatey/choco.exe.old".
Attempting to delete file "C:\ProgramData\chocolatey\choco.exe.old".
Command line not shown - sensitive arguments may have been passed.
RemovePendingPackagesTask is now ready and waiting for PreRunMessage.
Sending message 'PreRunMessage' out if there are subscribers...
[Pending] Removing all pending packages that should not be considered installed...
The source 'https://servername:7005/' evaluated to a 'normal' source type

NOTE: Hiding sensitive configuration data! Please double and triple
check to be sure no sensitive data is shown, especially if copying
output to a gist for review.
Configuration: CommandName='push'|
CacheLocation='path\chocolatey'|
ContainsLegacyPackageInstalls='True'|
CommandExecutionTimeoutSeconds='2700'|WebRequestTimeoutSeconds='30'|
Sources='https://servername:7005/'|SourceType='normal'|
Debug='True'|Verbose='True'|Trace='True'|Force='False'|Noop='False'|
HelpRequested='False'|UnsuccessfulParsing='False'|RegularOutput='True'|
QuietOutput='False'|PromptForConfirmation='True'|AcceptLicense='False'|
AllowUnofficialBuild='False'|Input='.\packagename.nupkg'|
AllVersions='False'|SkipPackageInstallProvider='False'|
Prerelease='False'|ForceX86='False'|OverrideArguments='False'|
NotSilent='False'|ApplyPackageParametersToDependencies='False'|
ApplyInstallArgumentsToDependencies='False'|IgnoreDependencies='False'|
AllowMultipleVersions='False'|AllowDowngrade='False'|
ForceDependencies='False'|Information.PlatformType='Windows'|
Information.PlatformVersion='6.2.9200.0'|
Information.PlatformName='Windows Server 2012'|
Information.ChocolateyVersion='0.10.5.0'|
Information.ChocolateyProductVersion='0.10.5'|
Information.FullName='choco, Version=0.10.5.0, Culture=neutral, PublicKeyToken=79d02ea9cad655eb'|

Information.Is64BitOperatingSystem='True'|
Information.Is64BitProcess='True'|Information.IsInteractive='True'|
Information.IsUserAdministrator='True'|
Information.IsProcessElevated='True'|
Information.IsLicensedVersion='False'|Information.LicenseType='Foss'|
Features.AutoUninstaller='True'|Features.ChecksumFiles='True'|
Features.AllowEmptyChecksums='False'|
Features.AllowEmptyChecksumsSecure='True'|
Features.FailOnAutoUninstaller='False'|
Features.FailOnStandardError='False'|Features.UsePowerShellHost='True'|
Features.LogEnvironmentValues='False'|Features.VirusCheck='False'|
Features.FailOnInvalidOrMissingLicense='False'|
Features.IgnoreInvalidOptionsSwitches='True'|
Features.UsePackageExitCodes='True'|
Features.UseFipsCompliantChecksums='False'|
Features.ShowNonElevatedWarnings='True'|
Features.ShowDownloadProgress='True'|
Features.StopOnFirstPackageFailure='False'|
Features.UseRememberedArgumentsForUpgrades='False'|
Features.ScriptsCheckLastExitCode='False'|
ListCommand.LocalOnly='False'|
ListCommand.IncludeRegistryPrograms='False'|ListCommand.PageSize='25'|
ListCommand.Exact='False'|ListCommand.ByIdOnly='False'|
ListCommand.IdStartsWith='False'|ListCommand.OrderByPopularity='False'|
ListCommand.ApprovedOnly='False'|
ListCommand.DownloadCacheAvailable='False'|
ListCommand.NotBroken='False'|
ListCommand.IncludeVersionOverrides='False'|
UpgradeCommand.FailOnUnfound='False'|
UpgradeCommand.FailOnNotInstalled='False'|
UpgradeCommand.NotifyOnlyAvailableUpgrades='False'|
UpgradeCommand.ExcludePrerelease='False'|
NewCommand.AutomaticPackage='False'|
NewCommand.UseOriginalTemplate='False'|SourceCommand.Command='unknown'|
SourceCommand.Priority='0'|SourceCommand.BypassProxy='False'|
SourceCommand.AllowSelfService='False'|
FeatureCommand.Command='unknown'|
ConfigCommand.Command='unknown'|PinCommand.Command='unknown'|
Proxy.BypassOnLocal='True'|
_ Chocolatey:ChocolateyPushCommand - Normal Run Mode _
Attempting to push package.nupkg to https://servername:7005/
System.Net Information: 0 : [7508] Associating HttpWebRequest#45028263 with ServicePoint#2601186
System.Net Information: 0 : [7508] Associating Connection#23410681 with HttpWebRequest#45028263
System.Net.Sockets Information: 0 : [7508] Socket#9369539 - Created connection from ip:63753 to ip:7005.
System.Net Information: 0 : [7508] Connection#23410681 - Created connection from ip:63753 to ip:7005.
System.Net Information: 0 : [7508] TlsStream#20735233::.ctor(host=servername, #certs=0)
System.Net Information: 0 : [7508] Associating HttpWebRequest#45028263 with ConnectStream#52399374
System.Net Information: 0 : [7508] HttpWebRequest#45028263 - Request: GET / HTTP/1.0

System.Net Information: 0 : [7508] ConnectStream#52399374 - Sending headers
{
User-Agent: NuGet/0.10.5.0 (Microsoft Windows NT 6.2.9200.0)
Host: servername:7005
}.
System.Net Information: 0 : [7508] SecureChannel#1832323::.ctor(hostname=servername, #clientCertificates=0, encryptionPolicy=RequireEncryption)
System.Net Information: 0 : [7508] Enumerating security packages:
System.Net Information: 0 : [7508] Negotiate
System.Net Information: 0 : [7508] NegoExtender
System.Net Information: 0 : [7508] Kerberos
System.Net Information: 0 : [7508] NTLM
System.Net Information: 0 : [7508] TSSSP
System.Net Information: 0 : [7508] pku2u
System.Net Information: 0 : [7508] CloudAP
System.Net Information: 0 : [7508] WDigest
System.Net Information: 0 : [7508] Schannel
System.Net Information: 0 : [7508] Microsoft Unified Security Protocol Provider
System.Net Information: 0 : [7508] CREDSSP
System.Net Information: 0 : [7508] SecureChannel#1832323 - Left with 0 client certificates to choose from.
System.Net Information: 0 : [7508] AcquireCredentialsHandle(package = Microsoft Unified Security Protocol Provider, intent = Outbound, scc = System.Net.SecureCredential)
System.Net Information: 0 : [7508] InitializeSecurityContext(credential = System.Net.SafeFreeCredential_SECURITY, context = (null), targetName = servername, inFlags = ReplayDetect, SequenceDetect, Confidentiality, AllocateMemory, InitManualCredValidation)
System.Net Information: 0 : [7508] InitializeSecurityContext(In-Buffer length=0, Out-Buffer length=184, returned code=ContinueNeeded).
System.Net Error: 0 : [7508] Exception in HttpWebRequest#45028263:: - The underlying connection was closed: An unexpected error occurred on a send..
System.Net Information: 0 : [7508] Associating HttpWebRequest#45028263 with ServicePoint#2601186
System.Net Information: 0 : [7508] Associating Connection#16490914 with HttpWebRequest#45028263
System.Net.Sockets Information: 0 : [7508] Socket#14200498 - Created connection from ip:63754 to ip:7005.
System.Net Information: 0 : [7508] Connection#16490914 - Created connection from ip:63754 to 172.16.176.191:7005.
System.Net Information: 0 : [7508] TlsStream#9389685::.ctor(host=servername, #certs=0)
System.Net Information: 0 : [7508] Associating HttpWebRequest#45028263 with ConnectStream#17398306
System.Net Information: 0 : [7508] HttpWebRequest#45028263 - Request: GET / HTTP/1.0

System.Net Information: 0 : [7508] ConnectStream#17398306 - Sending headers
{
User-Agent: NuGet/0.10.5.0 (Microsoft Windows NT 6.2.9200.0)
Host: servername:7005
}.
System.Net Information: 0 : [7508] SecureChannel#22367029::.ctor(hostname=servername, #clientCertificates=0, encryptionPolicy=RequireEncryption)
System.Net Information: 0 : [7508] SecureChannel#22367029 - Left with 0 client certificates to choose from.
System.Net Information: 0 : [7508] Using the cached credential handle.
System.Net Information: 0 : [7508] InitializeSecurityContext(credential = System.Net.SafeFreeCredential_SECURITY, context = (null), targetName = servername, inFlags = ReplayDetect, SequenceDetect, Confidentiality, AllocateMemory, InitManualCredValidation)
System.Net Information: 0 : [7508] InitializeSecurityContext(In-Buffer length=0, Out-Buffer length=184, returned code=ContinueNeeded).
System.Net Error: 0 : [7508] Exception in HttpWebRequest#45028263:: - The underlying connection was closed: An unexpected error occurred on a send..
System.Net Error: 0 : [7508] Exception in HttpWebRequest#45028263::GetResponse - The underlying connection was closed: An unexpected error occurred on a send..
Chocolatey had an error occur:
System.Net.WebException: The underlying connection was closed: An unexpected error occurred on a send. ---> System.IO.IOException: The handshake failed due to an unexpected packet format.
at System.Net.Security.SslState.StartReadFrame(Byte[] buffer, Int32 readBytes, AsyncProtocolRequest asyncRequest)
at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest)
at System.Net.Security.SslState.ForceAuthentication(Boolean receiveFirst, Byte[] buffer, AsyncProtocolRequest asyncRequest)
at System.Net.Security.SslState.ProcessAuthentication(LazyAsyncResult lazyResult)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Net.TlsStream.ProcessAuthentication(LazyAsyncResult result)
at System.Net.TlsStream.Write(Byte[] buffer, Int32 offset, Int32 size)
at System.Net.ConnectStream.WriteHeaders(Boolean async)
--- End of inner exception stack trace ---
at System.Net.HttpWebRequest.GetResponse()
at NuGet.RequestHelper.GetResponse()
at NuGet.RedirectedHttpClient.GetResponseUri(HttpClient client)
at NuGet.RedirectedHttpClient.EnsureClient()
at System.Lazy1.CreateValue() at System.Lazy1.LazyInitValue()
at NuGet.MemoryCache.GetOrAdd[T](Object cacheKey, Func1 factory, TimeSpan expiration, Boolean absoluteExpiration) at NuGet.RedirectedHttpClient.get_CachedClient() at NuGet.RedirectedHttpClient.get_Uri() at NuGet.PackageServer.ResolveBaseUrl() at System.Lazy1.CreateValue()
at System.Lazy1.LazyInitValue() at NuGet.PackageServer.GetClient(String path, String method, String contentType) at NuGet.PackageServer.PushPackageToServer(String apiKey, Func1 packageStreamFactory, Int64 packageSize, Int32 timeout, Boolean disableBuffering)
at chocolatey.infrastructure.app.nuget.NugetPush.push_package(ChocolateyConfiguration config, String nupkgFilePath)
at chocolatey.infrastructure.app.services.NugetService.push_run(ChocolateyConfiguration config)
at chocolatey.infrastructure.app.services.ChocolateyPackageService.push_run(ChocolateyConfiguration config)
at chocolatey.infrastructure.app.runners.GenericRunner.run(ChocolateyConfiguration config, Container container, Boolean isConsole, Action`1 parseArgs)
at chocolatey.infrastructure.app.runners.ConsoleApplication.run(String[] args, ChocolateyConfiguration config, Container container)
at chocolatey.console.Program.Main(String[] args)
Exiting with 1

[ferventcoder]

Closed on accident or did you find the issue?

[Outek]

No i gave up on this issue and installed a Server with local storage. The issue above is from Server with smb share.

[ferventcoder]

That's fine, it doesn't fix the issue that was logged though, so we'll keep it open.

[ferventcoder]

That way if other folks happen upon this issue, it can be picked up again for triage.

[Outek]

a little update on this
i try to push locally to the fqdn of the server without http and everything works fine.
With https everything(website/installations) is working fine, EXCEPT the push-function

[vexx32]

@Outek are you able to confirm at all whether this is still an issue?

[Outek]

No, it is not.

[vexx32]

Thank you! 💖