Bug 4018 - Using SSLIOP with a TAO client strategy that uses non-blocking recv socket call may chop one byte from beginning of the data
Summary: Using SSLIOP with a TAO client strategy that uses non-blocking recv socket ca...
Status: NEW
Alias: None
Product: TAO
Classification: Unclassified
Component: SSLIOP Pluggable Protocol (show other bugs)
Version: 2.0.7
Hardware: x86 Windows 2008
: P3 normal
Assignee: DOC Center Support List (internal)
URL:
Depends on:
Blocks:
 
Reported: 2012-05-08 03:37 CDT by panu
Modified: 2012-05-08 03:37 CDT (History)
0 users

See Also:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description panu 2012-05-08 03:37:27 CDT 
TAO VERSION: 2.0.7
ACE VERSION: 6.0.7

HOST MACHINE and OPERATING SYSTEM:
	Client: Windows 7 Enterprise x64 (ACE 6.0.7 + TAO 2.0.7 with SSL: openssl-1.0.0g), Winsock 1.1

TARGET MACHINE and OPERATING SYSTEM, if different from HOST:
	Server: Linux Centos 5.8 x64 (jvm running with OpenORB 1.4.0 + SSL 1.4.0)

COMPILER NAME AND VERSION (AND PATCHLEVEL):
	Visual Studio 2010 SP1 & Visual Studio 2008 SP1

THE $ACE_ROOT/ace/config.h:
	#include "ace/config-win32.h"


My build notes follow (nothing special except including the ssl build):

----------- (build notes ) -----------
	  
Preparations & modifications to build later ACE+TAO-6.0.7 with SSLIOP support
(4 combinations: VC9/10 & 32/64-bit!)
        
--- config.h ---
#include "ace/config-win32.h"
--- config.h ---

Release builds modified to have also debug info to be built!
Exploit multi-cpu's while building (/MP added)
ssl=1

So MWC tool must be used to create new VS project files and the solution file

set ACE_ROOT=D:\basedir\Corba\ACE+TAO-6.0.7\ACE_wrappers
set TAO_ROOT=%ACE_ROOT%\TAO

cd %TAO_ROOT%
%ACE_ROOT%\bin\mwc.pl -type vc9 -name_modifier *_vc9_vx TAO_ACE.mwc
%ACE_ROOT%\bin\mwc.pl -type vc10 -name_modifier *_vc10_vx TAO_ACE.mwc

---------

Note: correct openssl platform (same 4 combination!) must have been pre-built and env variable pointing to it, e.g.
SSL_ROOT=D:\basedir\Corba\openssl-1.0.0g

Only project SSLIOP is needed to be built (all the related projects are automatically build with it!)

----------- (build notes ) -----------


SYNOPSIS:
Using SSLIOP with a TAO client strategy that uses non-blocking recv socket call may chop one byte from beginning of the data

DESCRIPTION:
Simple client - server: client (ACE+TAO) makes requests and server (OpenORB) replies.
Slow network (=VPN over internet)

Using SSLIOP with a TAO client strategy that uses non-blocking recv socket call:
--- svc.conf (non-blocking recv) ---
dynamic SSLIOP_Factory Service_Object *
        TAO_SSLIOP:_make_TAO_SSLIOP_Protocol_Factory()
          "-SSLAuthenticate NONE"

static Resource_Factory "-ORBProtocolFactory SSLIOP_Factory"
--- svc.conf (non-blocking recv) ---

Read 1 byte successfully (=G of string GIOP!)
=> n times read failure - Resource temporarily unavailable errno 10035 (=normal, no data available, yet!)
=> finally data available, read in xxxx bytes (in one or more chunks)
=> TAO_GIOP_Message_State::parse_magic_bytes, bad IIOP header: magic word [49,4f,50,01] (=string IOP and 01!)
=> error (=the byte 'G' got chopped errorneously from the real data)

REPEAT BY:
Repeatable every time there's at least one "too fast recv" call:
SSLIOP_Transport[3460]::recv, read failure - Resource temporarily unavailable errno 10035

Makes no difference if the build is VS2008/VS2010 or 32/64-bit

Extract from level 10 log file:

TAO (7016|6052) - Transport[3460]::drain_queue_helper, end of data
TAO (7016|6052) - Transport[3460]::cleanup_queue, byte_count = 456
TAO (7016|6052) - Transport[3460]::cleanup_queue, after transfer, bc = 0, all_sent = 1, ml = 0
TAO (7016|6052) - Transport[3460]::drain_queue_helper, byte_count = 456, head_is_empty = 1
TAO (7016|6052) - Transport[3460]::drain_queue_i, helper retval = 1
TAO (7016|6052) - Transport[3460]::make_idle
TAO (7016|6052) - Cache_IntId_T::recycle_state, ENTRY_BUSY->ENTRY_IDLE_AND_PURGABLE Transport[3460] IntId=000000000B53EF10
TAO (7016|6052) - Leader_Follower[3460]::wait_for_event, (leader) enter reactor event loop
TAO (7016|6052) - Connection_Handler[3460]::handle_input_internal, handle = 3460/3460
TAO (7016|6052) - Transport[3460]::handle_input
TAO (7016|6052) - Transport[3460]::process_queue_head, 0 enqueued
TAO (7016|6052) - Transport[3460]::handle_input_parse_data, enter
TAO (7016|6052) - Transport[3460]::handle_input_parse_data, read 1 bytes
TAO (7016|6052) - Connection_Handler[3460]::handle_input_internal, handle = 3460/3460, retval = 0
TAO (7016|6052) - Connection_Handler[3460]::handle_input_internal, handle = 3460/3460
TAO (7016|6052) - Transport[3460]::handle_input
TAO (7016|6052) - Transport[3460]::process_queue_head, 0 enqueued
TAO (7016|6052) - Transport[3460]::handle_input_parse_data, enter
TAO (7016|6052) - SSLIOP_Transport[3460]::recv, read failure - Resource temporarily unavailable errno 10035
TAO (7016|6052) - Connection_Handler[3460]::handle_input_internal, handle = 3460/3460, retval = 0
TAO (7016|6052) - Connection_Handler[3460]::handle_input_internal, handle = 3460/3460
TAO (7016|6052) - Transport[3460]::handle_input
TAO (7016|6052) - Transport[3460]::process_queue_head, 0 enqueued
TAO (7016|6052) - Transport[3460]::handle_input_parse_data, enter
TAO (7016|6052) - Transport[3460]::handle_input_parse_data, read 1032 bytes
TAO (7016|6052) - GIOP_Message_State::parse_message_header_i
TAO (7016|6052) - TAO_GIOP_Message_State::parse_magic_bytes, bad IIOP header: magic word [49,4f,50,01]
TAO (7016|6052) - Transport[3460]::handle_input, error parsing incoming message
TAO (7016|6052) - Resume_Handle::handle_input_return_value_hook, handle_input returning -1, so handle is not resumed.
TAO (7016|6052) - Connection_Handler[3460]::handle_input_internal, handle = 3460/3460, retval = -1
TAO (7016|6052) - Connection_Handler[3460]::close_connection_eh, purging entry from cache
TAO (7016|6052) - Transport[3460]::pre_close
TAO (7016|6052) - Transport_Cache_Manager_T::mark_connected, false Transport[3460]
TAO (7016|6052) - Transport[3460]::purge_entry, entry is 000000000B53EF00
TAO (7016|6052) - Transport[3460]::cleanup_queue_i, cleaning up complete queue
TAO (7016|6052) - Transport[3460]::cleanup_queue_i, discarded 0 messages, 0 bytes.
TAO (7016|6052) - Connection_Handler[3460]::close_connection_eh, removing from the reactor
TAO (7016|6052) - Connection_Handler[3460]::close_connection_eh, cancel all timers
TAO (7016|6052) - Transport[3460]::cleanup_queue_i, cleaning up complete queue
TAO (7016|6052) - Transport[3460]::cleanup_queue_i, discarded 0 messages, 0 bytes.
TAO (7016|6052) - TAO_LF_CH_Event[3460]::state_changed_i, state LFS_SUCCESS->LFS_CONNECTION_CLOSED
TAO (7016|6052) - Connection_Handler[3460]::close_connection_eh end
TAO (7016|6052) - Leader_Follower[3460]::wait_for_event, (leader) exit reactor event loop
TAO (7016|6052) - Synch_Twoway_Invocation::wait_for_reply, recovering after an error
TAO (7016|6052) - Transport[3460]::~Transport


SAMPLE FIX/WORKAROUND:

Use of blocking recv calls (-ORBClientConnectionHandler RW):
--- svc.conf (blocking recv) ---
dynamic SSLIOP_Factory Service_Object *
        TAO_SSLIOP:_make_TAO_SSLIOP_Protocol_Factory()
          "-SSLAuthenticate NONE"

static Resource_Factory "-ORBProtocolFactory SSLIOP_Factory -ORBFlushingStrategy blocking"
static Client_Strategy_Factory "-ORBTransportMuxStrategy EXCLUSIVE -ORBClientConnectionHandler RW -ORBConnectStrategy blocked"
--- svc.conf (blocking recv) ---