NSIS-ka
A free C++ implementation of NSIS protocols

Opened 10 years ago

Last modified 10 years ago

#71 new defect

No Graceful behavior if TLS connection setup fails...

Reported by: bless Owned by: bless
Priority: major Milestone:
Component: GIST Version:
Keywords: Cc:

Description (last modified by bless)

Program crashes if TLS connection setup fails

2007-08-03 17:10:18.620-19663- EVENT /4: GIST Signaling  Sending msg to Protocol #254 (UNKNOWN) Dest:::ffff:141.3.71.201
2007-08-03 17:10:18.620-19663- DEBUG /8: TPoverTLS_TCP   >>--Connect-->> to ::ffff:141.3.71.201 port #30001 from ::ffff:141.3.71.65 port #48821
2007-08-03 17:10:18.621-19663- DEBUG /4: TPoverTLS_TCP   Before creation of a new SSL object
2007-08-03 17:10:18.621-19663- DEBUG /4: TPoverTLS_TCP   Before binding it to the socket
2007-08-03 17:10:18.622-19663- DEBUG /4: TPoverTLS_TCP   Bound SSL object to the socket
2007-08-03 17:10:18.623-19663**ERROR**2: TPoverTLS_TCP   SSL connect failed in get_connection_to(): sslv3 alert handshake failure
2007-08-03 17:10:18.623-19663- DEBUG /4: TPoverTLS_TCP   Inserted SSL object into sslmap
2007-08-03 17:10:18.624-19663- DEBUG /8: TPoverTLS_TCP   Connected to ::ffff:141.3.71.201, port #30001 via socket 12
2007-08-03 17:10:18.624-19663- EVENT /4: TPoverTLS_TCP   Starting new receiver thread...
2007-08-03 17:10:18.624-19663- DEBUG /8: TPoverTLS_TCP   receiver - New receiver thread <2888838032> started.
2007-08-03 17:10:18.624-19663- DEBUG /8: TPoverTLS_TCP   receiver - Preparing to wait for data at socket 12 from [IPv4-mapped address]: ::ffff:141.3.71.201:30001, UNKNOWN
2007-08-03 17:10:18.625-19663- DEBUG /4: TPoverTLS_TCP   SSL looked up, trying to connect
2007-08-03 17:10:18.625-19663**ERROR**4: TPoverTLS_TCP   sender   - TCP error, returns -1, error : Resource temporarily unavailable
terminate called after throwing an instance of 'protlib::TPError'
  what():  internal error
Aborted (core dumped)

or like this:

2007-08-07 15:46:38.807-16408- EVENT /4: TPoverTLS_TCP   Starting new sender thread...
2007-08-07 15:46:38.807-16408- EVENT /4: TPoverTLS_TCP   senderthread - starting as thread <2897398672>
2007-08-07 15:46:38.807-16408- DEBUG /8: TPoverTLS_TCP   No existing connection to ::ffff:141.3.71.201 port #30001 found, creating a new one.
2007-08-07 15:46:38.809-16408- DEBUG /8: TPoverTLS_TCP   >>--Connect-->> to ::ffff:141.3.71.201 port #30001 from ::ffff:141.3.71.65 port #56267
2007-08-07 15:46:38.809-16408- DEBUG /4: TPoverTLS_TCP   Before creation of a new SSL object
2007-08-07 15:46:38.809-16408- DEBUG /4: TPoverTLS_TCP   Before binding it to the socket
2007-08-07 15:46:38.809-16408- DEBUG /4: TPoverTLS_TCP   Bound SSL object to the socket
2007-08-07 15:46:38.816-16408**ERROR**2: TPoverTLS_TCP   SSL connect failed in get_connection_to(): sslv3 alert handshake failure
2007-08-07 15:46:38.816-16408- DEBUG /4: TPoverTLS_TCP   Inserted SSL object into sslmap
2007-08-07 15:46:38.816-16408- DEBUG /8: TPoverTLS_TCP   Connected to ::ffff:141.3.71.201, port #30001 via socket 12
2007-08-07 15:46:38.816-16408- EVENT /4: TPoverTLS_TCP   Starting new receiver thread...
2007-08-07 15:46:38.816-16408- DEBUG /4: TPoverTLS_TCP   SSL looked up, trying to connect
2007-08-07 15:46:38.816-16408- DEBUG /8: TPoverTLS_TCP   receiver - New receiver thread <2889005968> started.
2007-08-07 15:46:38.816-16408- DEBUG /8: TPoverTLS_TCP   receiver - Preparing to wait for data at socket 12 from [IPv4-mapped address]: ::ffff:141.3.71.201:30001, UNKNOWN
2007-08-07 15:46:38.821-16408- DEBUG /4: GIST Signaling  Received incoming message #112 on Queue
...
...
2007-08-07 15:46:43.811-16408**ERROR**4: TPoverTLS_TCP   sender   - TCP error, returns -1, error : Success
2007-08-07 15:46:43.812-16408- DEBUG /8: TPoverTLS_TCP   receiver - Other side ([IPv4-mapped address]: ::ffff:141.3.71.201:30001, UNKNOWN) closed connection for socket 12
2007-08-07 15:46:43.838-16408- DEBUG /4: TPoverTLS_TCP   bytes_received - common_header_length: 4294967288msgcontentlength: 0>=
2007-08-07 15:46:43.838-16408- DEBUG /4: TPoverTLS_TCP   receiver - Thread <2889005968> shutting down and closing socket [IPv4-mapped address]: ::ffff:141.3.71.201:30001, UNKNOWN
2007-08-07 15:46:43.839-16408- DEBUG /4: TPoverTLS_TCP   receiver - Thread <2889005968> terminated
2007-08-07 15:46:43.839-16408- DEBUG /4: TPoverTLS_TCP   receiver - Signaling main loop for cleanup
terminate called after throwing an instance of 'protlib::TPError'
2007-08-07 15:46:43.839-16408- DEBUG /4: TPoverTLS_TCP   Got cleanup request for thread <2889005968>
2007-08-07 15:46:43.839-16408- EVENT /4: TPoverTLS_TCP   cleanup_receiver_thread() - Receiver thread <2889005968> is terminated
2007-08-07 15:46:43.839-16408- DEBUG /4: TPoverTLS_TCP   cleanup_receiver_thread() - Cleanup receiver thread <2889005968>. Done.
  what():  internal error
2007-08-07 15:46:43.842-16408- DEBUG /8: TPoverTCP       receiver - Other side ([IPv4-mapped address]: ::ffff:141.3.71.201:30000, tcp) closed connection for socket 11
2007-08-07 15:46:43.846-16408- DEBUG /4: TPoverTCP       bytes_received-common_header_length=4294967288 msgcontentlength: 0

Newer dump: querier side

2008-02-20 14:52:10.232-25046- DEBUG /8: TPoverTLS_TCP   >>--Connect-->> to ::ffff:141.3.71.201 port #30001 from ::ffff:141.3.71.202 port #32936
2008-02-20 14:52:10.232-25046- DEBUG /4: NTLP_pdu        calculated PDU size of: 64
2008-02-20 14:52:10.233-25046- DEBUG /8: NTLPprotocol    starting to serialize
2008-02-20 14:52:10.233-25046- DEBUG /4: NTLP_pdu        calculated PDU size of: 64
2008-02-20 14:52:10.233-25046- DEBUG /4: NTLP_pdu        ntlp_pdu::serialize: data expected pdulen:64
2008-02-20 14:52:10.233-25046- DEBUG /8: NTLPprotocol    PDU serialized.
2008-02-20 14:52:10.233-25046- EVENT /4: GIST Signaling  Sending msg to Protocol #254 (UNKNOWN) Dest:::ffff:141.3.71.201
2008-02-20 14:52:10.233-25046- DEBUG /4: TPoverTLS_TCP   Before creation of a new SSL object
2008-02-20 14:52:10.233-25046- DEBUG /4: TPoverTLS_TCP   Before binding it to the socket
2008-02-20 14:52:10.233-25046- DEBUG /4: TPoverTLS_TCP   Bound SSL object to the socket
2008-02-20 14:52:10.251-25046**ERROR**2: TPoverTLS_TCP   SSL connect failed in get_connection_to(): sslv3 alert handshake failure
2008-02-20 14:52:10.251-25046- DEBUG /4: TPoverTLS_TCP   Inserted SSL object into sslmap
2008-02-20 14:52:10.251-25046- DEBUG /8: TPoverTLS_TCP   Connected to ::ffff:141.3.71.201, port #30001 via socket 33
2008-02-20 14:52:11.873-25046- DEBUG /8: TimerModule     sent reply mid 273 for elapsed timer 59 to Coordination (ext)
2008-02-20 14:52:11.873-25046- DEBUG /4: GIST Routing    Timer Handler called for timer mid 273
2008-02-20 14:52:11.873-25046- DEBUG /8: TimerModule     got 1 elapsed timer(s)
2008-02-20 14:52:11.873-25046- DEBUG /4: GIST Routing    Obsolete timer received
2008-02-20 14:52:12.222-25046- DEBUG /8: TimerModule     sent reply mid 540 for elapsed timer 145 to Coordination (ext)
2008-02-20 14:52:12.222-25046- DEBUG /4: GIST Processing to_queue_poll(): looking up routing key
2008-02-20 14:52:12.222-25046- DEBUG /8: TimerModule     got 1 elapsed timer(s)
2008-02-20 14:52:12.222-25046- DEBUG /4: GIST Routing    ******* Returning SII 11 with state QN_ESTABLISHED
2008-02-20 14:52:12.222-25046- DEBUG /4: GIST Processing Timer slot 3, timer is valid, id: 540
2008-02-20 14:52:12.222-25046- DEBUG /4: GIST Processing Queue Poll timer encountered empty data queue, not restarting
2008-02-20 14:52:12.222-25046- DEBUG /4: GIST Routing    ******* Unlocking SII 11 with state QN_ESTABLISHED
2008-02-20 14:52:15.250-25046**ERROR**4: TPoverTLS_TCP   sender   - TLS/TCP error, returns -1, error : Success
terminate called after throwing an instance of 'protlib::TPErrorSendFailed'
  what():  Failure while trying to send a protocol data unit
Aborted (core dumped)

Responder side:

2008-02-20 14:53:00.645-22049- EVENT /4: TPoverUDP       sender   - >>----Sent---->> message (168 bytes) using socket 5 to [IPv4-mapped address]: ::ffff:141.3.71.202:4, udp
2008-02-20 14:53:00.650-22049**ERROR**2: TPoverTLS_TCP   Unable to load client certificate
2008-02-20 14:53:00.650-22049**ERROR**2: TPoverTLS_TCP   Unable to load private Key, reason:system lib
2008-02-20 14:53:00.650-22049**ERROR**2: TPoverTLS_TCP   Private Key failed verification against CA
2008-02-20 14:53:00.668-22049**ERROR**2: TPoverTLS_TCP   SSL connect failed
2008-02-20 14:53:00.668-22049- DEBUG /4: TPoverTLS_TCP   SSL handle saved for future use with that socket
2008-02-20 14:53:00.668-22049- DEBUG /4: TPoverTLS_TCP   <<--Received connect--<< request from ::ffff:141.3.71.202 port #32936
2008-02-20 14:53:00.668-22049- EVENT /4: TPoverTLS_TCP   Starting new receiver thread...
2008-02-20 14:53:00.668-22049- DEBUG /8: TPoverTLS_TCP   receiver - New receiver thread <2887764880> started.
2008-02-20 14:53:00.668-22049- DEBUG /8: TPoverTLS_TCP   receiver - Preparing to wait for data at socket 12 from [IPv4-mapped address]: ::ffff:141.3.71.202:32936, UNKNOWN
2008-02-20 14:53:00.773-22049- DEBUG /4: TPoverTLS_TCP   Signaled receiver thread <2887764880> for termination
2008-02-20 14:53:05.668-22049- EVENT /8: TPoverTLS_TCP   receiver - Thread <2887764880> found terminate signal after poll
2008-02-20 14:53:05.829-22049- DEBUG /8: TPoverTCP       receiver - Other side ([IPv4-mapped address]: ::ffff:141.3.71.202:30000, tcp) closed connection for socket 11
2008-02-20 14:53:05.829-22049- DEBUG /4: TPoverTCP       bytes_received-common_header_length=4294967288 msgcontentlength: 0
2008-02-20 14:53:05.829-22049- DEBUG /4: TPoverTCP       receiver - Thread <2896157584> shutting down and closing socket [IPv4-mapped address]: ::ffff:141.3.71.202:30000, tcp
2008-02-20 14:53:05.829-22049- DEBUG /4: TPoverTCP       receiver - Thread <2896157584> terminated
2008-02-20 14:53:05.829-22049- DEBUG /4: TPoverTCP       receiver - Signaling main loop for cleanup
2008-02-20 14:53:05.829-22049- DEBUG /4: TPoverTCP       Got cleanup request for thread <2896157584>
2008-02-20 14:53:05.829-22049- EVENT /4: TPoverTCP       cleanup_receiver_thread() - Receiver thread <2896157584> is terminated
2008-02-20 14:53:05.829-22049- DEBUG /4: TPoverTCP       cleanup_receiver_thread() - Cleanup receiver thread <2896157584>. Done.
2008-02-20 14:53:05.829-22049- EVENT /4: TPoverTCP       senderthread - <2904550288> terminated connection.
2008-02-20 14:53:05.829-22049- EVENT /2: TPoverTLS_TCP   receiver - Poll hung up

Change History (4)

comment:1 Changed 10 years ago by bless

  • Description modified (diff)

comment:2 Changed 10 years ago by bless

  • Description modified (diff)

comment:3 Changed 10 years ago by bless

This is also related to tickets #58 and #32

comment:4 Changed 10 years ago by bless

  • Description modified (diff)
Note: See TracTickets for help on using tickets.