Bug 2355

Summary: oneway op. with timeout crashes client due to server termination
Product: TAO Reporter: jan.zima <jan.zima>
Component: ORBAssignee: DOC Center Support List (internal) <tao-support>
Status: RESOLVED FIXED    
Severity: critical    
Priority: P2    
Version: 1.4.8   
Hardware: x86   
OS: Windows XP   
Bug Depends on: 2417    
Bug Blocks:    

Description jan.zima 2006-01-09 03:45:42 CST
Client invoking oneway op. with timeout crashes due to server termination with
"pure virtual method called".

REPEAT BY:
       download: http://devel.webpark.cz/test_timeout_and_one_way.tgz
       make
       run test_server.bat
       run test_client_one.bat
       run test_client_two.bat
       terminate test_server.exe
       test_client_one crashes with "pure virtual method called"

       copy of log:

SERVER

$ ./test_server.bat
    (1828) INITIALIZATION ORB
    (1828) CREATE DATA SERVER
    (1828) IOR:
'IOR:010000001800000049444c3a546573742f546573745365727665723a312e300001000000000
0000070000000010102000a0000003132372e302e302e3100813e2800000014010f004e535401000
0000100000000000000010000004e414d455f544553545345525645525f310200000000000000080
0000001000000004f415401000000140000000100000001000100000000000901010000000000'

    (1828) SLEEP:3600

    (3552) Call TestOw dp_index:1
    (3552) Call TestOw dp_index:2
    (2852) Call TestOw dp_index:3
    (2852) Call TestOw dp_index:4
    (3520) Call TestOw dp_index:5
    (3520) Call TestOw dp_index:6
    (3552) Call TestOw dp_index:7
    (3552) Call TestOw dp_index:8
    (2852) Call TestOw dp_index:9
    (2852) Call TestOw dp_index:10
    (3520) Call TestOw dp_index:11
    (3520) Call TestOw dp_index:12
    (3552) Call TestOw dp_index:13
    (3552) Call TestOw dp_index:14
    (2852) Call TestOw dp_index:15
    (2852) Call TestOw dp_index:16
    (3520) Call TestOw dp_index:17
    (3552) Call TestTw dp_index:1
    (3520) Call TestOw dp_index:18
    (2852) Call TestTw dp_index:2
    (3552) Call TestOw dp_index:19
    (3520) Call TestTw dp_index:3
    (2852) Call TestOw dp_index:20
    (3520) Call TestTw dp_index:4
    (3552) Call TestOw dp_index:21
    (3520) Call TestTw dp_index:5
    (3520) Call TestOw dp_index:22
    (2852) Call TestTw dp_index:6
    (3520) Call TestOw dp_index:23
    (3552) Call TestTw dp_index:7
    (3520) Call TestOw dp_index:24
    (2852) Call TestTw dp_index:8
    (3552) Call TestOw dp_index:25
    (3520) Call TestTw dp_index:9
    (2852) Call TestOw dp_index:26
    (3520) Call TestTw dp_index:10
    (3552) Call TestOw dp_index:27
    (3520) Call TestTw dp_index:11

Kill -- CTRL+C

CLIENT OW

$ ./test_client_one.bat
    (1860) INITIALIZATION ORB
    (1860) CREATE TEST CLIENT
            (1860) Connect::MakeConnection - connect
string:'iiop://1.2@localhost:16001/NAME_TESTSERVER_1'
    (1860) Call - TestOw:0
    (1860) Call - TestOw:1
    (1860) Call - TestOw:2
    (1860) Call - TestOw:3
    (1860) Call - TestOw:4
    (1860) Call - TestOw:5
    (1860) Call - TestOw:6
    (1860) Call - TestOw:7
    (1860) Call - TestOw:8
    (1860) Call - TestOw:9
    (1860) Call - TestOw:10
    (1860) Call - TestOw:11
    (1860) Call - TestOw:12
    (1860) Call - TestOw:13
    (1860) Call - TestOw:14
    (1860) Call - TestOw:15
    (1860) Call - TestOw:16
    (1860) Call - TestOw:17
    (1860) Call - TestOw:18
    (1860) Call - TestOw:19
    (1860) Call - TestOw:20
    (1860) Call - TestOw:21
    (1860) Call - TestOw:22
    (1860) Call - TestOw:23
    (1860) Call - TestOw:24
    (1860) Call - TestOw:25
    (1860) Call - TestOw:26
    (1860) Call - TestOw:27
(808|1860) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'
OMG minor code (2), described as 'No usable profile in IOR.', completed = NO

        (1860) Connect::Flusher - error (exit from testserver_flusher->flush).
    (1860) test_conn.Flusher - ERROR
(808|1860) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'
OMG minor code (2), described as 'No usable profile in IOR.', completed = NO

    (1860) error (exit from TestOw).
    (1860) Call - TestOw:28
pure virtual method called

This application has requested the Runtime to terminate it in an unusual way.
Please contact the application's support team for more information.

CLIENT TW

$ ./test_client_two.bat
    (2132) INITIALIZATION ORB
    (2132) CREATE TEST CLIENT
            (2132) Connect::MakeConnection - connect
string:'iiop://1.2@localhost:16001/NAME_TESTSERVER_1'
    (2132) Call - TestTw:0
    (2132) Call - TestTw:1
    (2132) Call - TestTw:2
    (2132) Call - TestTw:3
    (2132) Call - TestTw:4
    (2132) Call - TestTw:5
    (2132) Call - TestTw:6
    (2132) Call - TestTw:7
    (2132) Call - TestTw:8
    (2132) Call - TestTw:9
    (2132) Call - TestTw:10
    (2132) Call - TestTw:11
(3356|2132) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'
OMG minor code (2), described as 'No usable profile in IOR.', completed = NO

    (2132) error (exit from TestTw).
    (2132) Call - TestTw:12
(3356|2132) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'
OMG minor code (2), described as 'No usable profile in IOR.', completed = NO

    (2132) error (exit from TestTw).
    (2132) Call - TestTw:13
(3356|2132) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TIMEOUT:1.0'
TAO exception, minor code = 79 (timeout during connect; low 7 bits of errno: 121
Unknown error), completed = NO

    (2132) error (exit from TestTw).
    (2132) Call - TestTw:14
(3356|2132) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'
OMG minor code (2), described as 'No usable profile in IOR.', completed = NO

    (2132) error (exit from TestTw).
    (2132) Call - TestTw:15
(3356|2132) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'
OMG minor code (2), described as 'No usable profile in IOR.', completed = NO

    (2132) error (exit from TestTw).
    (2132) Call - TestTw:16
(3356|2132) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'
OMG minor code (2), described as 'No usable profile in IOR.', completed = NO

    (2132) error (exit from TestTw).
    (2132) Call - TestTw:17
(3356|2132) EXCEPTION, Exception caught:
system exception, ID 'IDL:omg.org/CORBA/TRANSIENT:1.0'
OMG minor code (2), described as 'No usable profile in IOR.', completed = NO

Kill -- CTRL+C
Comment 1 jan.zima 2006-01-09 03:54:57 CST
Corected host version and target version.
Comment 2 Johnny Willemsen 2006-03-06 14:16:43 CST
looks very much at bug 2323. Could you please update the regression that it runs
automatically with perl as the other regressions. Also it must be portable and
could you then attach it to this bugzilla entry?
Comment 3 jan.zima 2006-03-07 02:49:10 CST
I'll try, same behaviour have Oneway_Buffering test when server is stoped.
It's dependent on Messaging policy SYNC_NONE set.
We found some new hack around this:
in Invocation_Adapter.cpp Invocation_Adapter::invoke_remote_i

// Create the resolver which will pick (or create) for us a
// transport and a profile from the effective_target.
Profile_Transport_Resolver resolver (
  effective_target.in (),
  stub,
  1);
 // (details.response_flags () != Messaging::SYNC_NONE));


Stack trace from our tests:

__nxm_thread_kill,                                                            
FP=20002d0fbf0
pthread_kill,                                                                 
FP=20002d0fbf0
tis_raise,                                                                    
FP=20002d0fc50
abort,                                                                        
FP=20002d0fc60
_ZN9__gnu_cxx27__verbose_terminate_handlerEv,                                 
FP=20002d0fc90
_ZN10__cxxabiv111__terminateEPFvvE,                                           
FP=20002d0fcc0
_ZSt9terminatev,                                                              
FP=20002d0fce0
__cxa_pure_virtual,                                                           
FP=20002d0fcf0
TAO_Transport::remove_reference,                                              
FP=20002d0fd00
TAO_Cache_IntId::~TAO_Cache_IntId,                                            
FP=20002d0fd10
ACE_Hash_Map_Entry<TAO_Cache_ExtId,TAO_Cache_IntId>::~ACE_Hash_Map_Entry,     
FP=20002d0fd20
ACE_Hash_Map_Manager_Ex<TAO_Cache_ExtId,TAO_Cache_IntId,ACE_Hash<TAO_Cache_ExtId>,ACE_Equal_To<TAO_Cache_ExtId>,ACE_Null_Mutex>::
      >unbind_i, FP=20002d0fd50
TAO_Transport_Cache_Manager::purge_entry_i,                                   
FP=20002d0fd70
TAO_Transport::purge_entry,                                                   
FP=20002d0fd90
TAO_Transport::not-in-charge ~TAO_Transport,                                  
FP=20002d0fde0
TAO_IIOP_Transport::in-charge-deleting ~TAO_IIOP_Transport,                   
FP=20002d0fe30
TAO_IIOP_Connection_Handler::in-charge-deleting ~TAO_IIOP_Connection_Handler, 
FP=20002d0fe60
ACE_Event_Handler::remove_reference,                                          
FP=20002d0fe90
TAO_Transport::remove_reference,                                              
FP=20002d0fec0
TAO::Profile_Transport_Resolver::~Profile_Transport_Resolver,                 
FP=20002d0fed0
TAO::Invocation_Adapter::invoke_remote_i,                                     
FP=20002d0fee0
TAO::Invocation_Adapter::invoke_i,                                            
FP=20002d0ff70
TAO::Invocation_Adapter::invoke,                                              
FP=20002d0ffd0
Madap::DataServer::WriteDpSeqDoubleOw,                                        
FP=20002d100b0
MadapInit::DS_WriteDpSeqDouble,                                               
FP=20002d101a0
m_DS_WriteDpSeqDouble,                                                        
FP=20002d102e0
CallObjects,                                                                  
FP=20002d10380
ThreadFunc,                                                                   
FP=20002d3dba0
__thdBase,                                                                    
FP=20002d3dc00
Comment 4 Johnny Willemsen 2006-03-07 03:32:46 CST
your change really is not correct, you disable a lot of stuff in the orb. This
seems the same as 2417.
Comment 5 Johnny Willemsen 2006-03-07 08:59:40 CST
accept
Comment 6 Johnny Willemsen 2006-04-19 07:56:58 CDT
Wed Apr 19 07:48:12 UTC 2006  Johnny Willemsen  <jwillemsen@remedy.nl>