TclTLS: Check-in [cb680e9fde]

Overview

Comment:	Added more input and output function error logging
Downloads:	Tarball \| ZIP archive \| SQL archive
Timelines:	family \| ancestors \| descendants \| both \| tls-1.8
Files:	files \| file ages \| folders
SHA3-256:	cb680e9fdec5d47805a5b8e96609002264e2ce6dad7b653f84ae4e8a5d131c40
User & Date:	bohagan on 2024-06-07 02:38:03
Other Links:	branch diff \| manifest \| tags

Context

2024-06-07
23:02		Test case fixes check-in: 0e844836ab user: bohagan tags: tls-1.8
02:38		Added more input and output function error logging check-in: cb680e9fde user: bohagan tags: tls-1.8
2024-06-06
13:54		Optimized checks for when to call Tls_WaitForConnect check-in: 9c66e07d09 user: bohagan tags: tls-1.8

Changes

Modified generic/tlsIO.c from [dd6b55b1c0] to [93e5605483].

︙
257 258 259 260 261 262 263 264 265 266 267 268 269 270	257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273	+ + +	case SSL_ERROR_WANT_WRITE: case SSL_ERROR_WANT_X509_LOOKUP: case SSL_ERROR_WANT_CONNECT: case SSL_ERROR_WANT_ACCEPT: case SSL_ERROR_WANT_ASYNC: case SSL_ERROR_WANT_ASYNC_JOB: case SSL_ERROR_WANT_CLIENT_HELLO_CB: #if OPENSSL_VERSION_NUMBER >= 0x30000000L case SSL_ERROR_WANT_RETRY_VERIFY: #endif default: /* The operation did not complete and should be retried later. / dprintf("Operation did not complete, call function again later: %i", rc); errorCodePtr = EAGAIN; dprintf("ERR(%d, %d) ", rc, *errorCodePtr); Tls_Error(statePtr, "Operation did not complete, call function again later"); return -1;
︙
294 295 296 297 298 299 300 ~~301~~ ~~302 303~~ 304 305 306 307 308 309 310	297 298 299 300 301 302 303 304 305 306 307 308 309 310 311	- + - -	* Reads input from the input device of the channel. * ------------------------------------------------------------------- / static int TlsInputProc(ClientData instanceData, char buf, int bufSize, int errorCodePtr) { unsigned long backingError; State statePtr = (State ) instanceData; ~~int bytesRead;~~ int bytesRead, err; ~~int err;~~ errorCodePtr = 0; dprintf("BIO_read(%d)", bufSize); / Skip if user verify callback is still running */ if (statePtr->flags & TLS_TCL_CALLBACK) { dprintf("Callback is running, reading 0 bytes");
︙
341 342 343 344 345 346 347 348 349 350 351 352 353 ~~354~~ 355 356 ~~357 358~~ 359 ~~360 361~~ 362 363 364 365 366 367 368 369 370 371	342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387	+ - - - + + + + + + + + + + + - - + + + + + + + +	* * Alternatively, we may want to handle the <0 return codes from * BIO_read specially (as advised in the RSA docs). TLS's lower level BIO * functions play with the retry flags though, and this seems to work * correctly. Similar fix in TlsOutputProc. - hobbs / ERR_clear_error(); / BIO_read, where 0 means EOF and -1 means error / bytesRead = BIO_read(statePtr->bio, buf, bufSize); dprintf("BIO_read -> %d", bytesRead); err = SSL_get_error(statePtr->ssl, bytesRead); backingError = ERR_get_error(); ~~#if 0~~ if (bytesRead <= 0) { if (BIO_should_retry(statePtr->bio)) { ~~dprintf("~~I/O~~ failed, will retry ba~~sed on EAGAIN"~~); errorCodePtr = EAGAIN;~~ dprintf("Read failed with code=%d, bytes read=%d: should retry", err, bytesRead); /* Some docs imply we should redo the BIO_read now / } else { dprintf("Read failed with code=%d, bytes read=%d: error condition", err, bytesRead); } / These are the same as BIO_retry_type / if (BIO_should_read(statePtr->bio)) { dprintf("BIO has insufficient data to read and return"); } if (BIO_should_write(statePtr->bio)) { dprintf("BIO has pending data to write"); ~~} #endif~~ } if (BIO_should_io_special(statePtr->bio)) { int reason = BIO_get_retry_reason(statePtr->bio); dprintf("BIO has some special condition other than read or write: code=%d", reason); } dprintf("BIO has pending data to write"); } switch (err) { case SSL_ERROR_NONE: / I/O operation completed / dprintf("SSL_ERROR_NONE"); dprintBuffer(buf, bytesRead); break; case SSL_ERROR_SSL: / A non-recoverable, fatal error in the SSL library occurred, usually a protocol error */ dprintf("SSL error, indicating that the connection has been aborted");
︙
387 388 389 390 391 392 393 394 395 396 397 398 399 400 401 402 403 404 405	403 404 405 406 407 408 409 410 411 412 413 414 415 416 417 418 419 420 421 422 423 424 425 426 427 428 429 430 431 432 433 434 435 436 437 438	+ + + + + + + + + + + + + + + + +	bytesRead = 0; Tls_Error(statePtr, "EOF reached"); } #endif break; case SSL_ERROR_WANT_READ: /* Op did not complete due to not enough data was available. Retry later. / dprintf("Got SSL_ERROR_WANT_READ, mapping this to EAGAIN"); bytesRead = -1; errorCodePtr = EAGAIN; Tls_Error(statePtr, "SSL_ERROR_WANT_READ"); break; case SSL_ERROR_WANT_WRITE: /* Op did not complete due to unable to sent all data to the BIO. Retry later. / dprintf("Got SSL_ERROR_WANT_WRITE, mapping this to EAGAIN"); bytesRead = -1; errorCodePtr = EAGAIN; Tls_Error(statePtr, "SSL_ERROR_WANT_WRITE"); break; case SSL_ERROR_WANT_X509_LOOKUP: /* Op didn't complete since callback set by SSL_CTX_set_client_cert_cb() asked to be called again / dprintf("Got SSL_ERROR_WANT_X509_LOOKUP, mapping it to EAGAIN"); errorCodePtr = EAGAIN; bytesRead = -1; Tls_Error(statePtr, "SSL_ERROR_WANT_X509_LOOKUP"); break; case SSL_ERROR_SYSCALL: /* Some non-recoverable, fatal I/O error occurred / dprintf("SSL_ERROR_SYSCALL"); if (backingError == 0 && bytesRead == 0) { / Unexpected EOF from the peer for OpenSSL 1.1 */
︙
419 420 421 422 423 424 425 426 427 428 429 430 431 432 433 434 435 436 437	452 453 454 455 456 457 458 459 460 461 462 463 464 465 466 467 468 469 470 471 472 473 474 475 476 477 478 479	+ + + + + + + + +	errorCodePtr = Tcl_GetErrno(); bytesRead = -1; Tls_Error(statePtr, ERR_reason_error_string(backingError)); } break; case SSL_ERROR_ZERO_RETURN: / Peer has closed the connection for writing by sending the close_notify alert. No more data can be read. / dprintf("Got SSL_ERROR_ZERO_RETURN, this means an EOF has been reached"); bytesRead = 0; errorCodePtr = 0; Tls_Error(statePtr, "Peer has closed the connection for writing by sending the close_notify alert"); break; case SSL_ERROR_WANT_ASYNC: /* Used with flag SSL_MODE_ASYNC, op didn't complete because an async engine is still processing data / dprintf("Got SSL_ERROR_WANT_ASYNC, mapping this to EAGAIN"); bytesRead = -1; errorCodePtr = EAGAIN; Tls_Error(statePtr, "SSL_ERROR_WANT_ASYNC"); break; default: dprintf("Unknown error (err = %i), mapping to EOF", err); *errorCodePtr = 0; bytesRead = 0; Tls_Error(statePtr, "Unknown error"); break;
︙
458 459 460 461 462 463 464 ~~465~~ 466 467 468 469 470 471 472	500 501 502 503 504 505 506 507 508 509 510 511 512 513	-	* ------------------------------------------------------------------- / static int TlsOutputProc(ClientData instanceData, const char buf, int toWrite, int errorCodePtr) { unsigned long backingError; State statePtr = (State ) instanceData; int written, err; errorCodePtr = 0; dprintf("BIO_write(%p, %d)", (void ) statePtr, toWrite); dprintBuffer(buf, toWrite); /* Skip if user verify callback is still running */ if (statePtr->flags & TLS_TCL_CALLBACK) {
︙
524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539 540 541 542 543 544 545	565 566 567 568 569 570 571 572 573 574 575 576 577 578 579 580 581 582 583 584 585 586 587 588 589 590 591 592 593 594 595 596 597 598 599 600 601 602 603 604 605 606 607 608 609 610 611 612	+ + + + + + + + + + + + + + + + + + + + + + + + + +	* * Alternatively, we may want to handle the <0 return codes from * BIO_write specially (as advised in the RSA docs). TLS's lower level * BIO functions play with the retry flags though, and this seems to * work correctly. Similar fix in TlsInputProc. - hobbs / ERR_clear_error(); / SSL_write will return 1 for success or 0 for failure / written = BIO_write(statePtr->bio, buf, toWrite); dprintf("BIO_write(%p, %d) -> [%d]", (void ) statePtr, toWrite, written); err = SSL_get_error(statePtr->ssl, written); backingError = ERR_get_error(); if (written <= 0) { if (BIO_should_retry(statePtr->bio)) { dprintf("Write failed with code %d, bytes written=%d: should retry", err, written); } else { dprintf("Write failed with code %d, bytes written=%d: error condition", err, written); } /* These are the same as BIO_retry_type / if (BIO_should_read(statePtr->bio)) { dprintf("BIO has insufficient data to read and return"); } if (BIO_should_write(statePtr->bio)) { dprintf("BIO has pending data to write"); } if (BIO_should_io_special(statePtr->bio)) { int reason = BIO_get_retry_reason(statePtr->bio); dprintf("BIO has some special condition other than read or write: code=%d", reason); } dprintf("BIO has pending data to write"); } else { BIO_flush(statePtr->bio); } switch (err) { case SSL_ERROR_NONE: / I/O operation completed */ dprintf("SSL_ERROR_NONE"); if (written < 0) { written = 0; } break; case SSL_ERROR_SSL:
︙
553 554 555 556 557 558 559 ~~560~~ 561 562 563 564 565 566 567 568 569 570 571 ~~572~~ 573 574 575 576 577 578 579	620 621 622 623 624 625 626 627 628 629 630 631 632 633 634 635 636 637 638 639 640 641 642 643 644 645 646 647 648 649 650 651 652 653	+ - + + + + + + + - +	Tls_Error(statePtr, "Unknown SSL error"); } errorCodePtr = ECONNABORTED; written = -1; break; case SSL_ERROR_WANT_READ: / Op did not complete due to not enough data was available. Retry later. / ~~dprintf(" write R ~~BLOCK~~");~~ dprintf("Got SSL_ERROR_WANT_READ, mapping it to EAGAIN"); errorCodePtr = EAGAIN; written = -1; Tls_Error(statePtr, "SSL_ERROR_WANT_READ"); break; case SSL_ERROR_WANT_WRITE: /* Op did not complete due to unable to sent all data to the BIO. Retry later. / dprintf("Got SSL_ERROR_WANT_WRITE, mapping it to EAGAIN"); errorCodePtr = EAGAIN; written = -1; Tls_Error(statePtr, "SSL_ERROR_WANT_WRITE"); break; case SSL_ERROR_WANT_X509_LOOKUP: /* Op didn't complete since callback set by SSL_CTX_set_client_cert_cb() asked to be called again / dprintf("Got SSL_ERROR_WANT_X509_LOOKUP, mapping it to EAGAIN"); errorCodePtr = EAGAIN; ~~~~dprintf("~~ write ~~X BLOCK")~~;~~ written = -1; Tls_Error(statePtr, "SSL_ERROR_WANT_X509_LOOKUP"); break; case SSL_ERROR_SYSCALL: /* Some non-recoverable, fatal I/O error occurred */ dprintf("SSL_ERROR_SYSCALL");
︙
594 595 596 597 598 599 600 601 602 603 604 605 606 607 608 609 610 611 612	668 669 670 671 672 673 674 675 676 677 678 679 680 681 682 683 684 685 686 687 688 689 690 691 692 693 694 695	+ + + + + + + + +	errorCodePtr = Tcl_GetErrno(); written = -1; Tls_Error(statePtr, ERR_reason_error_string(backingError)); } break; case SSL_ERROR_ZERO_RETURN: / Peer has closed the connection for writing by sending the close_notify alert. No more data can be read. / dprintf(" closed"); written = 0; errorCodePtr = 0; Tls_Error(statePtr, "Peer has closed the connection for writing by sending the close_notify alert"); break; case SSL_ERROR_WANT_ASYNC: /* Used with flag SSL_MODE_ASYNC, op didn't complete because an async engine is still processing data / dprintf("Got SSL_ERROR_WANT_ASYNC, mapping this to EAGAIN"); errorCodePtr = EAGAIN; written = -1; Tls_Error(statePtr, "SSL_ERROR_WANT_ASYNC"); break; default: dprintf("unknown error: %d", err); Tls_Error(statePtr, "Unknown error"); break; }
︙
794 795 796 797 798 799 800 801 802 803 804 805 806 807 808 ~~809 810~~ 811 812 813 814 815 816 817	877 878 879 880 881 882 883 884 885 886 887 888 889 890 891 892 893 894 895 896 897 898 899	+ - -	* TCL_READABLE, TCL_WRITABLE and TCL_EXCEPTION. / { Tcl_Channel downChan; State statePtr = (State ) instanceData; Tcl_DriverWatchProc watchProc; dprintf("TlsWatchProc(0x%x)", mask); dprintFlags(statePtr); /* Pretend to be dead as long as the verify callback is running. * Otherwise that callback could be invoked recursively. */ if (statePtr->flags & TLS_TCL_CALLBACK) { dprintf("Callback is on-going, doing nothing"); return; } ~~dprintFlags(statePtr);~~ downChan = Tls_GetParent(statePtr, TLS_TCL_FASTPATH); if (statePtr->flags & TLS_TCL_HANDSHAKE_FAILED) { dprintf("Asked to watch a socket with a failed handshake -- nothing can happen here"); dprintf("Unregistering interest in the lower channel"); watchProc = Tcl_ChannelWatchProc(Tcl_GetChannelType(downChan));
︙