Skip to content

Instantly share code, notes, and snippets.

@jasonmitchell

jasonmitchell/Description

Last active May 14, 2017 19:57
Show Gist options
  • Save jasonmitchell/28fd88d2ed4cff0b2fde35c25eff3c1a to your computer and use it in GitHub Desktop.
Save jasonmitchell/28fd88d2ed4cff0b2fde35c25eff3c1a to your computer and use it in GitHub Desktop.
Download ZIP
InvalidOperationException - "SslStream already authenticated"
Raw
Description
Single node
Any HTTPS request from external source.
Some extra logging added
Still exists on mono 5.0.0
Curl to https://127.0.0.1:2113/ping
Response received
"SslStream already authenticated" logged
Navigate to https://127.0.0.1:2113 in a browser
Browser receives 302 to /web/index.html
Browser does not receive response
IOStreams.SafelyDispose(..)
AsyncQueuedBufferWrite.Dispose()
AsyncQueuedBufferWriter.ContinueOnWriteOrStop()
Raw
Log
[04251,01,20:13:21.235]
ES VERSION: 0.0.0.0 (Unknown/Unknown, Unknown)
[04251,01,20:13:21.241] OS: Linux (Unix 4.4.0.75)
[04251,01,20:13:21.241] RUNTIME: 4.6.2 (Stable 4.6.2.16/ac9e222 Tue Jan 3 11:48:26 UTC 2017) (64-bit)
[04251,01,20:13:21.242] GC: 2 GENERATIONS
[04251,01,20:13:21.242] LOGS: /home/parallels/Dev/single-https-logs
[04251,01,20:13:21.246] MODIFIED OPTIONS:
CONFIG: ../single-https.yaml (Command Line)
MEM DB: true (Config File)
LOG: ../single-https-logs (Config File)
INT IP: 127.0.0.1 (Config File)
EXT IP: 127.0.0.1 (Config File)
INT TCP PORT: 1112 (Config File)
EXT TCP PORT: 1113 (Config File)
INT HTTP PORT: 2112 (Config File)
EXT HTTP PORT: 2113 (Config File)
INT HTTP PREFIXES: https://*:2112/ (Config File)
EXT HTTP PREFIXES: https://*:2113/ (Config File)
ADD INTERFACE PREFIXES: false (Config File)
USE HTTPS: true (Config File)
LOG HTTP REQUESTS: true (Config File)
DEFAULT OPTIONS:
HELP: False (<DEFAULT>)
VERSION: False (<DEFAULT>)
DEFINES: <empty> (<DEFAULT>)
WHAT IF: False (<DEFAULT>)
START STANDARD PROJECTIONS: False (<DEFAULT>)
DISABLE HTTP CACHING: False (<DEFAULT>)
MONO MIN THREADPOOL SIZE: 10 (<DEFAULT>)
INT SECURE TCP PORT: 0 (<DEFAULT>)
EXT SECURE TCP PORT ADVERTISE AS: 0 (<DEFAULT>)
EXT SECURE TCP PORT: 0 (<DEFAULT>)
EXT IP ADVERTISE AS: <empty> (<DEFAULT>)
EXT TCP PORT ADVERTISE AS: 0 (<DEFAULT>)
EXT HTTP PORT ADVERTISE AS: 0 (<DEFAULT>)
INT IP ADVERTISE AS: <empty> (<DEFAULT>)
INT SECURE TCP PORT ADVERTISE AS: 0 (<DEFAULT>)
INT TCP PORT ADVERTISE AS: 0 (<DEFAULT>)
INT HTTP PORT ADVERTISE AS: 0 (<DEFAULT>)
INT TCP HEARTBEAT TIMEOUT: 700 (<DEFAULT>)
EXT TCP HEARTBEAT TIMEOUT: 1000 (<DEFAULT>)
INT TCP HEARTBEAT INTERVAL: 700 (<DEFAULT>)
EXT TCP HEARTBEAT INTERVAL: 2000 (<DEFAULT>)
GOSSIP ON SINGLE NODE: False (<DEFAULT>)
FORCE: False (<DEFAULT>)
CLUSTER SIZE: 1 (<DEFAULT>)
NODE PRIORITY: 0 (<DEFAULT>)
MIN FLUSH DELAY MS: 2 (<DEFAULT>)
COMMIT COUNT: -1 (<DEFAULT>)
PREPARE COUNT: -1 (<DEFAULT>)
ADMIN ON EXT: True (<DEFAULT>)
STATS ON EXT: True (<DEFAULT>)
GOSSIP ON EXT: True (<DEFAULT>)
DISABLE SCAVENGE MERGING: False (<DEFAULT>)
SCAVENGE HISTORY MAX AGE: 30 (<DEFAULT>)
DISCOVER VIA DNS: True (<DEFAULT>)
CLUSTER DNS: fake.dns (<DEFAULT>)
CLUSTER GOSSIP PORT: 30777 (<DEFAULT>)
GOSSIP SEED: <empty> (<DEFAULT>)
STATS PERIOD SEC: 30 (<DEFAULT>)
CACHED CHUNKS: -1 (<DEFAULT>)
READER THREADS COUNT: 4 (<DEFAULT>)
CHUNKS CACHE SIZE: 536871424 (<DEFAULT>)
MAX MEM TABLE SIZE: 1000000 (<DEFAULT>)
HASH COLLISION READ LIMIT: 100 (<DEFAULT>)
DB: /var/lib/eventstore (<DEFAULT>)
INDEX: <empty> (<DEFAULT>)
SKIP DB VERIFY: False (<DEFAULT>)
WRITE THROUGH: False (<DEFAULT>)
UNBUFFERED: False (<DEFAULT>)
RUN PROJECTIONS: None (<DEFAULT>)
PROJECTION THREADS: 3 (<DEFAULT>)
WORKER THREADS: 5 (<DEFAULT>)
ENABLE TRUSTED AUTH: False (<DEFAULT>)
CERTIFICATE STORE LOCATION: <empty> (<DEFAULT>)
CERTIFICATE STORE NAME: <empty> (<DEFAULT>)
CERTIFICATE SUBJECT NAME: <empty> (<DEFAULT>)
CERTIFICATE THUMBPRINT: <empty> (<DEFAULT>)
CERTIFICATE FILE: <empty> (<DEFAULT>)
CERTIFICATE PASSWORD: <empty> (<DEFAULT>)
USE INTERNAL SSL: False (<DEFAULT>)
DISABLE INSECURE TCP: False (<DEFAULT>)
SSL TARGET HOST: n/a (<DEFAULT>)
SSL VALIDATE SERVER: True (<DEFAULT>)
AUTHENTICATION TYPE: internal (<DEFAULT>)
AUTHENTICATION CONFIG: <empty> (<DEFAULT>)
PREPARE TIMEOUT MS: 2000 (<DEFAULT>)
COMMIT TIMEOUT MS: 2000 (<DEFAULT>)
UNSAFE DISABLE FLUSH TO DISK: False (<DEFAULT>)
BETTER ORDERING: False (<DEFAULT>)
UNSAFE IGNORE HARD DELETE: False (<DEFAULT>)
INDEX CACHE DEPTH: 16 (<DEFAULT>)
GOSSIP INTERVAL MS: 1000 (<DEFAULT>)
GOSSIP ALLOWED DIFFERENCE MS: 60000 (<DEFAULT>)
GOSSIP TIMEOUT MS: 500 (<DEFAULT>)
ENABLE HISTOGRAMS: False (<DEFAULT>)
ALWAYS KEEP SCAVENGED: False (<DEFAULT>)
[04251,01,20:13:21.251] Quorum size set to 1
[04251,01,20:13:21.258] Cannot find plugins path: /home/parallels/Dev/EventStore/bin/clusternode/plugins
[04251,01,20:13:21.331] INSTANCE ID: f4b29704-bb05-4161-b139-10a80c5ce1ef
[04251,01,20:13:21.331] DATABASE: /tmp/EmbeddedEventStore/2017-05-11_20.13.21.252792-EmbeddedNode
[04251,01,20:13:21.332] WRITER CHECKPOINT: 0 (0x0)
[04251,01,20:13:21.332] CHASER CHECKPOINT: 0 (0x0)
[04251,01,20:13:21.332] EPOCH CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)
[04251,01,20:13:21.332] TRUNCATE CHECKPOINT: -1 (0xFFFFFFFFFFFFFFFF)
[04251,01,20:13:21.547] MessageHierarchy initialization took 00:00:00.1785915.
[04251,01,20:13:21.746] Starting MiniWeb for /web/es/js/projections ==> /home/parallels/Dev/EventStore/bin/clusternode/projections
[04251,01,20:13:21.746] Starting MiniWeb for /web/es/js/projections/v8/Prelude ==> /home/parallels/Dev/EventStore/bin/clusternode/Prelude
[04251,01,20:13:21.756] Starting MiniWeb for /web ==> /home/parallels/Dev/EventStore/bin/clusternode/clusternode-web
[04251,01,20:13:21.756] Binding MiniWeb to /web/{*remaining_path}
[04251,11,20:13:21.770] ========== [127.0.0.1:2112] SYSTEM INIT...
[04251,11,20:13:21.802] Starting Normal TCP listening on TCP endpoint: 127.0.0.1:1113.
[04251,12,20:13:21.825] TableIndex initialization...
[04251,12,20:13:21.831] ReadIndex building...
[04251,12,20:13:21.832] ReadIndex rebuilding done: total processed 0 records, time elapsed: 00:00:00.0009200.
[04251,11,20:13:21.855] SLOW BUS MSG [MainBus]: SystemInit - 48ms. Handler: TcpService.
[04251,11,20:13:21.874] Starting HTTP server on [https://*:2113/]...
[04251,11,20:13:21.902] HTTP server is up and listening on [https://*:2113/]
[04251,11,20:13:21.918] SLOW QUEUE MSG [MainQueue]: SystemInit - 145ms. Q: 0/6.
[04251,11,20:13:21.918] ========== [127.0.0.1:2112] Service 'StorageWriter' initialized.
[04251,11,20:13:21.918] ========== [127.0.0.1:2112] Service 'StorageReader' initialized.
[04251,11,20:13:21.919] ========== [127.0.0.1:2112] Service 'StorageChaser' initialized.
[04251,11,20:13:21.920] ========== [127.0.0.1:2112] SYSTEM START...
[04251,11,20:13:21.924] ========== [127.0.0.1:2112] IS UNKNOWN...
[04251,08,20:13:21.946] Subscriptions received state change to Unknown stopping listening.
[04251,11,20:13:21.965] ELECTIONS: STARTING ELECTIONS.
[04251,11,20:13:21.965] ELECTIONS: (V=0) SHIFT TO LEADER ELECTION.
[04251,11,20:13:21.966] ELECTIONS: (V=0) VIEWCHANGE FROM [127.0.0.1:2112, {f4b29704-bb05-4161-b139-10a80c5ce1ef}].
[04251,11,20:13:21.966] ELECTIONS: (V=0) MAJORITY OF VIEWCHANGE.
[04251,11,20:13:21.967] ELECTIONS: (V=0) SHIFT TO PREPARE PHASE.
[04251,11,20:13:21.967] ELECTIONS: (V=0) PREPARE_OK FROM [127.0.0.1:2112,{f4b29704-bb05-4161-b139-10a80c5ce1ef}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-0000-000000000000}).
[04251,11,20:13:21.968] ELECTIONS: (V=0) SHIFT TO REG_LEADER.
[04251,11,20:13:21.979] ELECTIONS: (V=0) SENDING PROPOSAL CANDIDATE: [127.0.0.1:2112,{f4b29704-bb05-4161-b139-10a80c5ce1ef}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-0000-000000000000}), ME: [127.0.0.1:2112,{f4b29704-bb05-4161-b139-10a80c5ce1ef}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-0000-000000000000}).
[04251,11,20:13:21.981] ELECTIONS: (V=0) ACCEPT FROM [127.0.0.1:2112,{f4b29704-bb05-4161-b139-10a80c5ce1ef}] M=[127.0.0.1:2112,{f4b29704-bb05-4161-b139-10a80c5ce1ef}]).
[04251,11,20:13:21.981] ELECTIONS: (V=0) DONE. ELECTED MASTER = [127.0.0.1:2112,{f4b29704-bb05-4161-b139-10a80c5ce1ef}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-0000-000000000000}). ME=[127.0.0.1:2112,{f4b29704-bb05-4161-b139-10a80c5ce1ef}](L=-1,W=0,C=0,E-1@-1:{00000000-0000-0000-0000-000000000000}).
[04251,11,20:13:21.984] SLOW BUS MSG [MainBus]: StartElections - 59ms. Handler: ElectionsService.
[04251,11,20:13:21.984] SLOW QUEUE MSG [MainQueue]: StartElections - 59ms. Q: 0/4.
[04251,11,20:13:21.985] ========== [127.0.0.1:2112] PRE-MASTER STATE, WAITING FOR CHASER TO CATCH UP...
[04251,07,20:13:21.985] Subscriptions received state change to PreMaster stopping listening.
[04251,11,20:13:21.990] ========== [127.0.0.1:2112] IS MASTER... SPARTA!
[04251,07,20:13:21.993] Subscriptions Became Master so now handling subscriptions
[04251,11,20:13:22.057] SLOW BUS MSG [MainBus]: ReadStreamEventsBackwardCompleted - 48ms. Handler: RequestResponseDispatcher`2.
[04251,11,20:13:22.057] SLOW QUEUE MSG [MainQueue]: ReadStreamEventsBackwardCompleted - 48ms. Q: 3/5.
[04251,09,20:13:22.162] === Writing E0@0:{8c763798-b03c-4008-9d8b-36e88eb6455a} (previous epoch at -1).
[04251,09,20:13:22.164] === Update Last Epoch E0@0:{8c763798-b03c-4008-9d8b-36e88eb6455a} (previous epoch at -1).
[04251,07,20:13:22.286] Created stats stream '$stats-127.0.0.1:2113', code = Success
[04251,11,20:13:22.319] 'admin' user account has been created.
[04251,11,20:13:22.320] 'ops' user account has been created.
[04251,11,20:13:22.323] 'admin' user added to $users.
[04251,11,20:13:22.324] 'ops' user added to $users.
[04251,17,20:13:22.365] PROJECTIONS: Starting Projections Core Coordinator. (Node State : Master)
[04251,11,20:13:22.380] ========== [127.0.0.1:2112] Sub System 'Projections' initialized.
[04251,17,20:13:22.418] PROJECTIONS: Starting Projections Manager. (Node State : Master)
[04251,17,20:13:22.420] SLOW QUEUE MSG [Projections Master]: SystemCoreReady - 82ms. Q: 0/3.
[04251,17,20:13:22.452] PROJECTIONS: Resetting Worker Writer
[04251,07,20:13:26.419] HTTP Request Received
5/11/2017 9:13:26 PM
From: 127.0.0.1:48784
GET https://127.0.0.1:2113/info
Host: 127.0.0.1:2113
User-Agent: curl/7.47.0
Accept: */*
[04251,07,20:13:26.427] HTTP Response
5/11/2017 9:13:26 PM
200 OK
Host: 127.0.0.1:2113
User-Agent: curl/7.47.0
Accept: */*
{
"esVersion": "0.0.0.0",
"state": "master",
"projectionsMode": "None"
}
[04251,16,20:13:26.458] Error while closing stream : This SslStream is already authenticated
[04251,16,20:13:26.458] at Mono.Net.Security.Private.LegacySslStream.BeginAuthenticateAsServer (System.Security.Cryptography.X509Certificates.X509Certificate serverCertificate, System.Boolean clientCertificateRequired, System.Security.Authentication.SslProtocols enabledSslProtocols, System.Boolean checkCertificateRevocation, System.AsyncCallback asyncCallback, System.Object asyncState) [0x0001f] in <5071a6e4a4564e19a2eda0f53e42f9bd>:0
at Mono.Net.Security.Private.LegacySslStream.AuthenticateAsServer (System.Security.Cryptography.X509Certificates.X509Certificate serverCertificate, System.Boolean clientCertificateRequired, System.Security.Authentication.SslProtocols enabledSslProtocols, System.Boolean checkCertificateRevocation) [0x00000] in <5071a6e4a4564e19a2eda0f53e42f9bd>:0
at System.Net.HttpConnection.Init () [0x0001d] in <5071a6e4a4564e19a2eda0f53e42f9bd>:0
at System.Net.HttpConnection.Close (System.Boolean force_close) [0x000e3] in <5071a6e4a4564e19a2eda0f53e42f9bd>:0
at System.Net.HttpListenerResponse.Close (System.Boolean force) [0x00012] in <5071a6e4a4564e19a2eda0f53e42f9bd>:0
at System.Net.HttpListenerResponse.Close () [0x0000c] in <5071a6e4a4564e19a2eda0f53e42f9bd>:0
at System.Net.ResponseStream.Close () [0x000cf] in <5071a6e4a4564e19a2eda0f53e42f9bd>:0
at System.IO.Stream.Dispose () [0x00000] in <8f2c484307284b51944a1a13a14c0266>:0
at (wrapper remoting-invoke-with-check) System.IO.Stream:Dispose ()
at EventStore.Transport.Http.IOStreams.SafelyDispose (System.IO.Stream[] streams) [0x0002a] in <e30dccdb264c4cb0b554c2323b18c5ae>:0
Raw
Reproduction.cs
using System;
using System.Net;
namespace HttpListenerTest
{
class Program
{
public static void Main(string[] args)
{
var httpListener = new HttpListener();
httpListener.Prefixes.Add("https://*:5443/");
httpListener.Start();
Console.WriteLine("Listening...");
while (httpListener.IsListening)
{
var context = httpListener.GetContext();
var response = context.Response;
response.OutputStream.Dispose(); // InvalidOperationException: "This SslStream is already authenticated"
response.Close();
}
}
}
}
Raw
single-https.yaml
MemDb: true
Log: ../single-https-logs
IntIp: 127.0.0.1
ExtIp: 127.0.0.1
IntTcpPort: 1112
ExtTcpPort: 1113
IntHttpPort: 2112
ExtHttpPort: 2113
IntHttpPrefixes: https://*:2112/
ExtHttpPrefixes: https://*:2113/
AddInterfacePrefixes: false
UseHttps: true
LogHttpRequests: true
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment