bifurcation / mint

A Minimal TLS 1.3 Implementation in Go
MIT License
224 stars 36 forks source link

"No appropriate certificate found" despite InsecureSkipVerify=true #194

Closed lthibault closed 6 years ago

lthibault commented 6 years ago

Hello, I'm trying to use quic-go, which uses mint internally.

I've set MINT_LOG="*" and attempted a connection using the runnable example provided here.

Here is the log output I get:

$ go run cmd/scratch/main.go                                                                                                                                                                                                                           (10s 752ms)
2018/05/13 15:30:41 started
2018/05/13 15:30:42 [crypto] HKDF Extract:
2018/05/13 15:30:42 [crypto] Salt [20]: 9c108f98520a5c5c32968e950e8a2c5fe06d6c38
2018/05/13 15:30:42 [crypto] Input [8]: 84d8172644ea6931
2018/05/13 15:30:42 [crypto] Output [32]: ae193f6f93b4b0ccbcf21028bd7933bf2192d679a70cd04cf32d306428e2fce4
2018/05/13 15:30:42 [handshake] [client] First time through handshake (or after stateless retry), setting up
2018/05/13 15:30:42 [handshake] opts: {ServerName:localhost NextProtos:[] EarlyData:[]}
2018/05/13 15:30:42 [handshake] [ClientStateStart] -> [ClientStateWaitSH]
2018/05/13 15:30:42 [handshake] [client] queuing handshake message type=1
2018/05/13 15:30:42 [handshake] Sending outgoing messages
2018/05/13 15:30:42 [handshake] WriteMessage [1] 030397e97e54a92de6b4cea324be66bd20b73bec7a144caadbcd412a36801f3b5e150000041301130201000243002b0003027f160000000e000c0000096c6f63616c686f7374002801d401d200170041040d7bb64e997574217a992c3ce9abd8a31abca9ac620e4f4651a15fdf7f4da11aee5de9752889a109d074301cb2d5ed26efe79b4e64a60d897400334781460e130018006104b17890e534eb7ba0774412160d20e23e9bdc8932e24d5a4ef6dc776fb7c6df2c1314de169f396b053b7977e3234654c49677ffdd9cbcfff451c7154e8951296ad47e24b7883bbee50f6087ae499f79f0b9c5454369521691db7629258d68367801000100f9d864ff28043052e94dff1e76952d249b378c0cf4e67e747a37e69c4723c14359a96b14cdb2e7ce2b6108e0de35ae65994019b09ed41faa8190cb839c8bfe02baed297c613487dbb047ff025e5e2413e98806c341ae311225375ba1f1cf6cce1009945ca45e74868fff371c99ea53867dd810fc75e595cd40ea96f33d440f099ee76e6c0a30a5238d58fbd6cbe5f27d03f56bc8ad00110b479468fce1a784c1d81d7325fda97440d564535b5e6695f319c1c59421614a699b80caeb209e19eaa3ccab2327ca00ca0ea8fdefcc4cab8606878785caeb12d402c15b169ead520e2eec500b1231cd411fe07751e0ca260b3d173a1d97ac16470083337b92c82886001d00209e9810c9427123d93a7577bfc5ffa411ef958ee455f4edca612b842eea8bb979000a000a0008001700180100001d000d000e000c080408050806040305030603001a002e0000000000280000000400008000000100040000c00000020002006400080002006400030002001e0005000205ac
2018/05/13 15:30:42 [io] RecordLayer.WriteRecord epoch=[clear] seq=[0000000000000000] [22] ciphertext=[01000270030397e97e54a92de6b4cea324be66bd20b73bec7a144caadbcd412a36801f3b5e150000041301130201000243002b0003027f160000000e000c0000096c6f63616c686f7374002801d401d200170041040d7bb64e997574217a992c3ce9abd8a31abca9ac620e4f4651a15fdf7f4da11aee5de9752889a109d074301cb2d5ed26efe79b4e64a60d897400334781460e130018006104b17890e534eb7ba0774412160d20e23e9bdc8932e24d5a4ef6dc776fb7c6df2c1314de169f396b053b7977e3234654c49677ffdd9cbcfff451c7154e8951296ad47e24b7883bbee50f6087ae499f79f0b9c5454369521691db7629258d68367801000100f9d864ff28043052e94dff1e76952d249b378c0cf4e67e747a37e69c4723c14359a96b14cdb2e7ce2b6108e0de35ae65994019b09ed41faa8190cb839c8bfe02baed297c613487dbb047ff025e5e2413e98806c341ae311225375ba1f1cf6cce1009945ca45e74868fff371c99ea53867dd810fc75e595cd40ea96f33d440f099ee76e6c0a30a5238d58fbd6cbe5f27d03f56bc8ad00110b479468fce1a784c1d81d7325fda97440d564535b5e6695f319c1c59421614a699b80caeb209e19eaa3ccab2327ca00ca0ea8fdefcc4cab8606878785caeb12d402c15b169ead520e2eec500b1231cd411fe07751e0ca260b3d173a1d97ac16470083337b92c82886001d00209e9810c9427123d93a7577bfc5ffa411ef958ee455f4edca612b842eea8bb979000a000a0008001700180100001d000d000e000c080408050806040305030603001a002e0000000000280000000400008000000100040000c00000020002006400080002006400030002001e0005000205ac]
2018/05/13 15:30:42 [handshake] Clearing outgoing hs message queue
2018/05/13 15:30:42 [handshake] (Re-)entering handshake, state={0xc42020a140 {localhost [] []} {false false false false false unknown localhost } {0xc420062960 0xc4200629c0} map[23:[58 94 198 86 71 22 75 71 20 126 90 103 121 54 193 143 239 211 229 183 205 37 86 67 59 54 211 196 225223 83 65] 24:[116 126 50 115 88 170 217 134 17 105 244 196 78 83 239 90 176 131 220 164 251 216 149 111 34 147 230 248 233 180 145 137 68 119 139 18 145 173 138 205 152 50 88 34 137 181 107 176] 256:[34 89 207 112 169 95 112 88 247 42 95 70 174 12 29 224 233 119 6 155 220 153 187 251 64 167 233 181 87 130 186 93 22 125 191 172 235 247 242 39 241 108 191 102 138 80 75 63 13 210 200 204 184 15 4 106 199 20 252 95 25 49 242 210 135 28 158 143 143 199 232 204 66 144 3 159 132 17 83 76 154 116 205 113 189 232 150 148 30 204 69 151 112 226 67 182 47 149 217 232 21188 21 181 84 230 80 72 8 235 106 185 220 142 201 5 10 123 69 178 62 224 223 6 159 147 234 33 237 172 9 252 120 106 10 118 35 160 29 213 68 143 164 60 32 70 73 39 97 2 222 253 180 233 238 184 150 83 36 157 81 237 59 132 38 227 216 44 164 85 94 35 253 161 198 53 97 108 181 215 43 173 33 146 92 22 48 202 47 55 151 78 53 234 248 55 23 128 123 250 131 122 120 108 3 157 1 72 43 108 241 139 132 77 19 108 138 123 42 144 103 147 176 190 118 88 198 148 88 148 0 203 218 58 208 207 100 183 48 136 202 176 176 53 68 248 60 220 143 75 224 105 124 204 53 84] 29:[15 134 174 192 93 76 29 248 229 195 131 150 75 0 57 236 134 2 93 158 68 123 110 6 154 211 165 46 21 222 156 167]] {unknown false [] []  0001-01-01 00:00:00 +0000 UTC 0001-01-01 00:00:00 +0000 UTC 0} [] [] 0 <nil> <nil> 0xc4200840f0}
2018/05/13 15:30:42 [verbose] ReadMessage() buffered=0
2018/05/13 15:30:42 [verbose] Trying to read a new record
2018/05/13 15:30:42 [verbose] Trying to read record
2018/05/13 15:30:42 [crypto] HKDF Extract:
2018/05/13 15:30:42 [crypto] Salt [20]: 9c108f98520a5c5c32968e950e8a2c5fe06d6c38
2018/05/13 15:30:42 [crypto] Input [8]: 84d8172644ea6931
2018/05/13 15:30:42 [crypto] Output [32]: ae193f6f93b4b0ccbcf21028bd7933bf2192d679a70cd04cf32d306428e2fce4
2018/05/13 15:30:42 [handshake] [server] First time through handshake (or after stateless retry), setting up
2018/05/13 15:30:42 [handshake] (Re-)entering handshake, state={0xc42020a3c0 0xc4200821a0 {0xc420062600 0xc420062660}}
2018/05/13 15:30:42 [verbose] ReadMessage() buffered=0
2018/05/13 15:30:42 [verbose] Trying to read a new record
2018/05/13 15:30:42 [verbose] Trying to read record
2018/05/13 15:30:42 [io] Read 633 bytes
2018/05/13 15:30:42 [frame] Appending 633
2018/05/13 15:30:42 [frame] 5 bytes needed for next block
2018/05/13 15:30:42 [frame] Processed header, body len = 628
2018/05/13 15:30:42 [frame] 628 bytes needed for next block
2018/05/13 15:30:42 [frame] Returning frame hdr=0x1603030274 len=628 buffered=0
2018/05/13 15:30:42 [io] RecordLayer.ReadRecord [22] [01000270030397e97e54a92de6b4cea324be66bd20b73bec7a144caadbcd412a36801f3b5e150000041301130201000243002b0003027f160000000e000c0000096c6f63616c686f7374002801d401d200170041040d7bb64e997574217a992c3ce9abd8a31abca9ac620e4f4651a15fdf7f4da11aee5de9752889a109d074301cb2d5ed26efe79b4e64a60d897400334781460e130018006104b17890e534eb7ba0774412160d20e23e9bdc8932e24d5a4ef6dc776fb7c6df2c1314de169f396b053b7977e3234654c49677ffdd9cbcfff451c7154e8951296ad47e24b7883bbee50f6087ae499f79f0b9c5454369521691db7629258d68367801000100f9d864ff28043052e94dff1e76952d249b378c0cf4e67e747a37e69c4723c14359a96b14cdb2e7ce2b6108e0de35ae65994019b09ed41faa8190cb839c8bfe02baed297c613487dbb047ff025e5e2413e98806c341ae311225375ba1f1cf6cce1009945ca45e74868fff371c99ea53867dd810fc75e595cd40ea96f33d440f099ee76e6c0a30a5238d58fbd6cbe5f27d03f56bc8ad00110b479468fce1a784c1d81d7325fda97440d564535b5e6695f319c1c59421614a699b80caeb209e19eaa3ccab2327ca00ca0ea8fdefcc4cab8606878785caeb12d402c15b169ead520e2eec500b1231cd411fe07751e0ca260b3d173a1d97ac16470083337b92c82886001d00209e9810c9427123d93a7577bfc5ffa411ef958ee455f4edca612b842eea8bb979000a000a0008001700180100001d000d000e000c080408050806040305030603001a002e0000000000280000000400008000000100040000c00000020002006400080002006400030002001e0005000205ac]
2018/05/13 15:30:42 [frame] Appending 628
2018/05/13 15:30:42 [frame] 4 bytes needed for next block
2018/05/13 15:30:42 [io] Header=01000270
2018/05/13 15:30:42 [frame] Processed header, body len = 624
2018/05/13 15:30:42 [frame] 624 bytes needed for next block
2018/05/13 15:30:42 [frame] Returning frame hdr=0x01000270 len=624 buffered=0
2018/05/13 15:30:42 [handshake] read handshake message
2018/05/13 15:30:42 [handshake] Read message with type: 1
2018/05/13 15:30:42 [handshake] Clearing outgoing hs message queue
2018/05/13 15:30:42 [handshake] [server] version offered by client [7f16] <> [7f16]
2018/05/13 15:30:42 [negotiation] Negotiating PSK modes [true] [false] [[]]
2018/05/13 15:30:42 [negotiation] Results of PSK mode negotiation: usingDH=[true] usingPSK=[false]
2018/05/13 15:30:42 [handshake] [ServerStateStart] -> [ServerStateStart]
2018/05/13 15:30:42 [handshake] [server] taking next action (0)
2018/05/13 15:30:42 [handshake] [server] queuing handshake message type=2
2018/05/13 15:30:42 [handshake] [server] taking next action (1)
2018/05/13 15:30:42 [handshake] Sending outgoing messages
2018/05/13 15:30:42 [handshake] WriteMessage [2] 0303cf21ad74e59a6111be1d8c021e65b891c2a211167abb8c5e079e09e2c8a8339c0013010000a1002b00027f16002c00970095787ed1e1a938694e21e86dad953e3b648d827c74bff580d53dde4b50e41b65aa483fd98f846866f8581d26bc89fabe9cf119b4e8e853736472e0bde70c5f4a77301454b8c49b7e9938527f125fe9a5453b5bf489a5c39ef6de0dac30ee72d09c34987b8979fe79529ad76bd91601fddfb03001c6f6aeac0312c61fc17b74b7f987eccd7baf6dcffd5df86640bb2a09b59e1f29bce8
2018/05/13 15:30:42 [io] RecordLayer.WriteRecord epoch=[clear] seq=[0000000000000000] [22] ciphertext=[020000c90303cf21ad74e59a6111be1d8c021e65b891c2a211167abb8c5e079e09e2c8a8339c0013010000a1002b00027f16002c00970095787ed1e1a938694e21e86dad953e3b648d827c74bff580d53dde4b50e41b65aa483fd98f846866f8581d26bc89fabe9cf119b4e8e853736472e0bde70c5f4a77301454b8c49b7e9938527f125fe9a5453b5bf489a5c39ef6de0dac30ee72d09c34987b8979fe79529ad76bd91601fddfb03001c6f6aeac0312c61fc17b74b7f987eccd7baf6dcffd5df86640bb2a09b59e1f29bce8]
2018/05/13 15:30:42 [handshake] Clearing outgoing hs message queue
2018/05/13 15:30:42 [handshake] state is now Server START
2018/05/13 15:30:42 [io] Read 210 bytes
2018/05/13 15:30:42 [frame] Appending 210
2018/05/13 15:30:42 [frame] 5 bytes needed for next block
2018/05/13 15:30:42 [frame] Processed header, body len = 205
2018/05/13 15:30:42 [frame] 205 bytes needed for next block
2018/05/13 15:30:42 [frame] Returning frame hdr=0x16030100cd len=205 buffered=0
2018/05/13 15:30:42 [io] RecordLayer.ReadRecord [22] [020000c90303cf21ad74e59a6111be1d8c021e65b891c2a211167abb8c5e079e09e2c8a8339c0013010000a1002b00027f16002c00970095787ed1e1a938694e21e86dad953e3b648d827c74bff580d53dde4b50e41b65aa483fd98f846866f8581d26bc89fabe9cf119b4e8e853736472e0bde70c5f4a77301454b8c49b7e9938527f125fe9a5453b5bf489a5c39ef6de0dac30ee72d09c34987b8979fe79529ad76bd91601fddfb03001c6f6aeac0312c61fc17b74b7f987eccd7baf6dcffd5df86640bb2a09b59e1f29bce8]
2018/05/13 15:30:42 [frame] Appending 205
2018/05/13 15:30:42 [frame] 4 bytes needed for next block
2018/05/13 15:30:42 [io] Header=020000c9
2018/05/13 15:30:42 [frame] Processed header, body len = 201
2018/05/13 15:30:42 [frame] 201 bytes needed for next block
2018/05/13 15:30:42 [frame] Returning frame hdr=0x020000c9 len=201 buffered=0
2018/05/13 15:30:42 [handshake] read handshake message
2018/05/13 15:30:42 [handshake] Read message with type: 2
2018/05/13 15:30:42 [handshake] Clearing outgoing hs message queue
2018/05/13 15:30:42 [handshake] [ClientStateWaitSH] -> [ClientStateStart]
2018/05/13 15:30:42 [handshake] state is now Client START
2018/05/13 15:30:42 [crypto] HKDF Extract:
2018/05/13 15:30:42 [crypto] Salt [20]: 9c108f98520a5c5c32968e950e8a2c5fe06d6c38
2018/05/13 15:30:42 [crypto] Input [8]: 84d8172644ea6931
2018/05/13 15:30:42 [crypto] Output [32]: ae193f6f93b4b0ccbcf21028bd7933bf2192d679a70cd04cf32d306428e2fce4
2018/05/13 15:30:42 [handshake] (Re-)entering handshake, state={0xc42020a140 {localhost [] []} {false false false false false unknown  } [120 126 209 225 169 56 105 78 33 232 109 173 149 62 59 100 141 130 124 116 191 245 128 213 61 222 75 80 228 27 101 170 72 63 217 143 132 104 102248 88 29 38 188 137 250 190 156 241 25 180 232 232 83 115 100 114 224 189 231 12 95 74 119 48 20 84 184 196 155 126 153 56 82 127 18 95 233 165 69 59 91 244 137 165 195 158 246 222 13 172 48 238 114 208 156 52 152 123 137 121 254 121 82 154 215 107 217 22 1 253 223 176 48 1 198 246 174 172 3 18 198 31 193 123 116 183 249 135 236 205 123 175 109 207 253 93 248 102 64 187 42 9 181 158 31 41 188 232] 0xc420320280 0xc420320230 {0xc420062960 0xc4200629c0}}
2018/05/13 15:30:42 [handshake] opts: {ServerName:localhost NextProtos:[] EarlyData:[]}
2018/05/13 15:30:42 [handshake] [ClientStateStart] -> [ClientStateWaitSH]
2018/05/13 15:30:42 [handshake] [client] taking next action (0)
2018/05/13 15:30:42 [handshake] [client] queuing handshake message type=1
2018/05/13 15:30:42 [handshake] [client] taking next action (1)
2018/05/13 15:30:42 [handshake] Sending outgoing messages
2018/05/13 15:30:42 [handshake] WriteMessage [1] 030384a8aadb113460a04607028e17f18c8a0860c2ee5af3ef856979ea19b3239a850000021301010002de002b0003027f160000000e000c0000096c6f63616c686f7374002801d401d20017004104c60c2f84b6370c7345977a64bad26bfa812ec65c405bc1aa24dc5f220d57f2b8a8bfacbf36e1f3b4ae564da910edb8b356eaff88c7b655dfc5839540d8da5f2b0018006104c5237e556e89882d77981ca36335e70762343db2a6ea388f1282eeed4819c08ad387630ed9f899b12559bb734d8cc2f2604fa61d0f1d98549cd43fdaaa881071041901a886d4db24221a78e8c83e60e932ff6f99f097c1b4b7877b95b8dd1a5501000100919347d13872dd985477c20459118fa5d9d28ba0a808ca413b341b7dd18f2c26633388cb1f40fdc824b9e077292bb20c2f441704cecf49ff06a9820aafaf8e301b7316603cbb42776938257e0fc7ed67d571610cf83091fa7cf9c98bf912b24fb82dd56d0e55afcbfd2b6f87ef8d15348ec5544f2208e459803097a0bc4326470b0340381527743f71d4147af527fd057a4f995d7bee1bee9d50166e8f4728cdc7e19a94bbd104eb42e431c4a1d66ea0273a714ae6d89ec7cb8a00ef38c0f578acf3d363883b6ab3a9bc087f4fcd1491e2efb3742be40b9baa85ef6bed9f883cb1a05575c248dd8e8e5439267639efe1ba21db49c8880ca2129840d297d7bcd1001d0020befaba7f67cc4d5486191c43a9bf249bd15429fe07fd79652e3f3761caf51b29000a000a0008001700180100001d000d000e000c080408050806040305030603002c00970095787ed1e1a938694e21e86dad953e3b648d827c74bff580d53dde4b50e41b65aa483fd98f846866f8581d26bc89fabe9cf119b4e8e853736472e0bde70c5f4a77301454b8c49b7e9938527f125fe9a5453b5bf489a5c39ef6de0dac30ee72d09c34987b8979fe79529ad76bd91601fddfb03001c6f6aeac0312c61fc17b74b7f987eccd7baf6dcffd5df86640bb2a09b59e1f29bce8001a002e0000000000280000000400008000000100040000c00000020002006400080002006400030002001e0005000205ac
2018/05/13 15:30:42 [io] RecordLayer.WriteRecord epoch=[clear] seq=[0000000000000001] [22] ciphertext=[01000309030384a8aadb113460a04607028e17f18c8a0860c2ee5af3ef856979ea19b3239a850000021301010002de002b0003027f160000000e000c0000096c6f63616c686f7374002801d401d20017004104c60c2f84b6370c7345977a64bad26bfa812ec65c405bc1aa24dc5f220d57f2b8a8bfacbf36e1f3b4ae564da910edb8b356eaff88c7b655dfc5839540d8da5f2b0018006104c5237e556e89882d77981ca36335e70762343db2a6ea388f1282eeed4819c08ad387630ed9f899b12559bb734d8cc2f2604fa61d0f1d98549cd43fdaaa881071041901a886d4db24221a78e8c83e60e932ff6f99f097c1b4b7877b95b8dd1a5501000100919347d13872dd985477c20459118fa5d9d28ba0a808ca413b341b7dd18f2c26633388cb1f40fdc824b9e077292bb20c2f441704cecf49ff06a9820aafaf8e301b7316603cbb42776938257e0fc7ed67d571610cf83091fa7cf9c98bf912b24fb82dd56d0e55afcbfd2b6f87ef8d15348ec5544f2208e459803097a0bc4326470b0340381527743f71d4147af527fd057a4f995d7bee1bee9d50166e8f4728cdc7e19a94bbd104eb42e431c4a1d66ea0273a714ae6d89ec7cb8a00ef38c0f578acf3d363883b6ab3a9bc087f4fcd1491e2efb3742be40b9baa85ef6bed9f883cb1a05575c248dd8e8e5439267639efe1ba21db49c8880ca2129840d297d7bcd1001d0020befaba7f67cc4d5486191c43a9bf249bd15429fe07fd79652e3f3761caf51b29000a000a0008001700180100001d000d000e000c080408050806040305030603002c00970095787ed1e1a938694e21e86dad953e3b648d827c74bff580d53dde4b50e41b65aa483fd98f846866f8581d26bc89fabe9cf119b4e8e853736472e0bde70c5f4a77301454b8c49b7e9938527f125fe9a5453b5bf489a5c39ef6de0dac30ee72d09c34987b8979fe79529ad76bd91601fddfb03001c6f6aeac0312c61fc17b74b7f987eccd7baf6dcffd5df86640bb2a09b59e1f29bce8001a002e0000000000280000000400008000000100040000c00000020002006400080002006400030002001e0005000205ac]
2018/05/13 15:30:42 [handshake] Clearing outgoing hs message queue
2018/05/13 15:30:42 [handshake] state is now Client WAIT_SH
2018/05/13 15:30:42 [handshake] (Re-)entering handshake, state={0xc42020a140 {localhost [] []} {false false false false false unknown localhost } {0xc420062960 0xc4200629c0} map[256:[77 161 169 95 75 62 226 59 47 205 172 146 18 201 81 245 13 31 184 18 34 219 254 192 58 105 219 208 75 204 68 148 11 135 248 141 49 242 165 203 139 2 115 131 139 171 58 31 7 56 21 106 9 188 167 6 220 31 136 26 8 201 196 216 115 196 190 249 147 16 98 185 202 158 49 206 92 141 43 30 63 124 151 114 164 68 23 206 17 251 203 55 161 18 10 168 106 217 23 72 21 213 74 152 73 49 47 253 168126 45 204 175 115 122 19 170 3 173 85 93 119 39 11 110 35 202 113 148 92 131 15 7 199 87 94 82 93 226 64 1 109 178 206 204 42 144 97 216 77 175 222 155 80 159 94 12 173 124 44 91 152 159 150 218 248 253 34 111 131 226 46 86 94 132 46 60 192 58 220 88 208 81 45 90 225 83 53 193 19948 21 231 231 166 176 141 41 54 246 69 70 219 75 59 228 96 125 9 9 182 160 132 82 80 0 20 235 236 79 163 203 139 184 27 54 94 30 88 25 60 208 70 53 178 252 158 70 17 106 18 161 64 36 110 207 20 66 43 44 146 110 76 231 99 125] 29:[54 129 185 51 98 58 170 18 79 52 135 248 137 19 179 23 255 206 129 125 115 61 157 211 190 192 67 74 255 19 226 181] 23:[9 63 172 191 154 96 94 121 209 37 28 168 20 163 214 59 244 248 51 191 14 7 219 12 167 247 242 43 59 164 224 123] 24:[13 38 189 194 158 252 148 36 37 35 92 207 251 89 228 251 227 214 110 193 115 235 215 144 75 139 29140 190 44 171 174 117 39 219 92 227 64 115 106 120 133 208 31 75 118 211 237]] {unknown false [] []  0001-01-01 00:00:00 +0000 UTC 0001-01-01 00:00:00 +0000 UTC 0} [] [] 0 0xc420320280 0xc420320230 0xc4200840f0}
2018/05/13 15:30:42 [verbose] ReadMessage() buffered=0
2018/05/13 15:30:42 [verbose] Trying to read a new record
2018/05/13 15:30:42 [crypto] HKDF Extract:
2018/05/13 15:30:42 [crypto] Salt [20]: 9c108f98520a5c5c32968e950e8a2c5fe06d6c38
2018/05/13 15:30:42 [crypto] Input [8]: 84d8172644ea6931
2018/05/13 15:30:42 [crypto] Output [32]: ae193f6f93b4b0ccbcf21028bd7933bf2192d679a70cd04cf32d306428e2fce4
2018/05/13 15:30:42 [verbose] Trying to read record
2018/05/13 15:30:42 [handshake] [server] First time through handshake (or after stateless retry), setting up
2018/05/13 15:30:42 [handshake] (Re-)entering handshake, state={0xc42020a280 0xc4200821a0 {0xc4202243c0 0xc420224420}}
2018/05/13 15:30:42 [verbose] ReadMessage() buffered=0
2018/05/13 15:30:42 [verbose] Trying to read a new record
2018/05/13 15:30:42 [verbose] Trying to read record
2018/05/13 15:30:42 [io] Read 786 bytes
2018/05/13 15:30:42 [frame] Appending 786
2018/05/13 15:30:42 [frame] 5 bytes needed for next block
2018/05/13 15:30:42 [frame] Processed header, body len = 781
2018/05/13 15:30:42 [frame] 781 bytes needed for next block
2018/05/13 15:30:42 [frame] Returning frame hdr=0x160303030d len=781 buffered=0
2018/05/13 15:30:42 [io] RecordLayer.ReadRecord [22] [01000309030384a8aadb113460a04607028e17f18c8a0860c2ee5af3ef856979ea19b3239a850000021301010002de002b0003027f160000000e000c0000096c6f63616c686f7374002801d401d20017004104c60c2f84b6370c7345977a64bad26bfa812ec65c405bc1aa24dc5f220d57f2b8a8bfacbf36e1f3b4ae564da910edb8b356eaff88c7b655dfc5839540d8da5f2b0018006104c5237e556e89882d77981ca36335e70762343db2a6ea388f1282eeed4819c08ad387630ed9f899b12559bb734d8cc2f2604fa61d0f1d98549cd43fdaaa881071041901a886d4db24221a78e8c83e60e932ff6f99f097c1b4b7877b95b8dd1a5501000100919347d13872dd985477c20459118fa5d9d28ba0a808ca413b341b7dd18f2c26633388cb1f40fdc824b9e077292bb20c2f441704cecf49ff06a9820aafaf8e301b7316603cbb42776938257e0fc7ed67d571610cf83091fa7cf9c98bf912b24fb82dd56d0e55afcbfd2b6f87ef8d15348ec5544f2208e459803097a0bc4326470b0340381527743f71d4147af527fd057a4f995d7bee1bee9d50166e8f4728cdc7e19a94bbd104eb42e431c4a1d66ea0273a714ae6d89ec7cb8a00ef38c0f578acf3d363883b6ab3a9bc087f4fcd1491e2efb3742be40b9baa85ef6bed9f883cb1a05575c248dd8e8e5439267639efe1ba21db49c8880ca2129840d297d7bcd1001d0020befaba7f67cc4d5486191c43a9bf249bd15429fe07fd79652e3f3761caf51b29000a000a0008001700180100001d000d000e000c080408050806040305030603002c00970095787ed1e1a938694e21e86dad953e3b648d827c74bff580d53dde4b50e41b65aa483fd98f846866f8581d26bc89fabe9cf119b4e8e853736472e0bde70c5f4a77301454b8c49b7e9938527f125fe9a5453b5bf489a5c39ef6de0dac30ee72d09c34987b8979fe79529ad76bd91601fddfb03001c6f6aeac0312c61fc17b74b7f987eccd7baf6dcffd5df86640bb2a09b59e1f29bce8001a002e0000000000280000000400008000000100040000c00000020002006400080002006400030002001e0005000205ac]
2018/05/13 15:30:42 [frame] Appending 781
2018/05/13 15:30:42 [frame] 4 bytes needed for next block
2018/05/13 15:30:42 [io] Header=01000309
2018/05/13 15:30:42 [frame] Processed header, body len = 777
2018/05/13 15:30:42 [frame] 777 bytes needed for next block
2018/05/13 15:30:42 [frame] Returning frame hdr=0x01000309 len=777 buffered=0
2018/05/13 15:30:42 [handshake] read handshake message
2018/05/13 15:30:42 [handshake] Read message with type: 1
2018/05/13 15:30:42 [handshake] Clearing outgoing hs message queue
2018/05/13 15:30:42 [handshake] [server] version offered by client [7f16] <> [7f16]
2018/05/13 15:30:42 [negotiation] Negotiating PSK modes [true] [false] [[]]
2018/05/13 15:30:42 [negotiation] Results of PSK mode negotiation: usingDH=[true] usingPSK=[false]
2018/05/13 15:30:42 [handshake] [ServerStateStart] No appropriate certificate found [No certificates available for server name: localhost]
2018/05/13 15:30:42 [handshake] Error in state transition: access denied
panic: HandshakeTimeout: Crypto handshake did not complete in time.

Of particular interest, the line that reads: [handshake] [ServerStateStart] No appropriate certificate found [No certificates available for server name: localhost].

I find this quite surprising since InsecureSkipVerify is set to true, which in my mind means no such checks are performed. Please note that this has been done to facilitate development, and does not represent a production setting.

My questions are as follows

  1. Is this a bug or intended behavior?
  2. Where/how can I set the hostname to avoid this error?

Many thanks in advance!

marten-seemann commented 6 years ago

InsecureSkipVerify is an option for the client side. This error occurs on the server side. One way to handle this is to do what the standard library does (it uses the certificate if there’s only one certificate chain), but iirc @bifurcation recently made the argument that such a fallback can have some ugly security implications.

lthibault commented 6 years ago

Okay, appending "localhost" to x509.Certificate.DNSNames seems to fix the issue.

Thanks.