[jacorb-developer] Execution order in server
David Gibbs
David.Gibbs at ig.com
Thu May 28 18:07:08 CEST 2015
Hi Phil,
Thanks for your reply. Yes, we're using IOR in this form.
It was the exception in 3.6 that attracted my attention so I'll test with an older version to see if I observe the same behaviour.
ORBInitRef.NameService=corbaloc:iiop:cns:5353/NameService
Thanks and regards
David Gibbs
Technical Manager
IG, Cannon Bridge House
25 Dowgate Hill London EC4R 2YA
D: +442075730697 | T: +442078960011
www.igmarkets.com
CREATING OPPORTUNITY
CFDs | SPREAD BETTING | FX
-----Original Message-----
From: Phil Mesnier [mailto:mesnier_p at ociweb.com]
Sent: 26 May 2015 18:08
To: Discussions concerning CORBA development with JacORB
Cc: David Gibbs
Subject: Re: [jacorb-developer] Execution order in server
Hi David,
Do you know if this is new behavior since any particular version?
I'm guessing you are using a CORBLOC IOR to reach a TAO name service? The RIR is sending an initial request and getting a location forward exception causing JacORB to rebind and retry. There has been a fair amount of work in the past few releases relating to retries under various circumstances, maybe something has introduced this new behavior. At least 3.6.1 doesn't throw an exception. The delay is interesting though. Another possibility is that this has been common behavior for a while and just the changes in 3.6 and 3.6.1 have raised your awareness of the issue?
Best regards,
Phil
> On May 26, 2015, at 9:07 AM, David Gibbs <David.Gibbs at ig.com> wrote:
>
> Hi
>
> I am using JacORB 3.6.1 and have noticed that JacORB is releasing and closing an extant connection to the naming service very soon after intialisation . See thread "ClientMessageReceptor0". Perhaps this is a result of a call to "resolve_initial_references". JacORB then opens a new connection.
> Does anyone else observe this behaviour ?
>
> ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> JacORB V3.6.1 (www.jacorb.org)
> (C) The JacORB project 1997-2015
> 19 May 2015 with SHA 93794019
> ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
> 2015-05-26 14:21:28,871 [main] DEBUG org.jacorb.poa.controller -
> RequestProcessorPoolFactory settings: thread_pool_min=5
> thread_pool_max=20 thread_pool_shared=false
> 2015-05-26 14:21:28,871 [main] INFO org.jacorb.orb - Initialising ORB with ID:
> 2015-05-26 14:21:28,871 [main] DEBUG org.jacorb.orb - added
> ORBInitializer:
> org.jacorb.orb.standardInterceptors.IORInterceptorInitializer
> 2015-05-26 14:21:28,871 [main] DEBUG org.jacorb.orb - Adding IORInterceptorInitializer manually is deprecated.
> 2015-05-26 14:21:28,871 [main] DEBUG org.jacorb.orb.factory -
> defaulting to DefaultSocketFactory
> 2015-05-26 14:21:28,887 [main] DEBUG org.jacorb.orb.giop - Maximum
> connection threads: 1000
> 2015-05-26 14:21:28,887 [main] DEBUG org.jacorb.orb.giop - Maximum
> idle threads: 5
> 2015-05-26 14:21:28,887 [main] DEBUG org.jacorb.orb - Property
> "jacorb.hashtable_class" is set to: java.util.Hashtable
> 2015-05-26 14:21:28,887 [main] INFO org.jacorb.orb.interceptors -
> InterceptorManager started with 0 Server Interceptors, 0 Client
> Interceptors and 1 IOR Interceptors
> 2015-05-26 14:21:28,918 [main] DEBUG uk.co.igindex.corba.clientbase.V2_0.BaseServiceDelegateImpl - initialising Service.
> 2015-05-26 14:21:28,918 [main] DEBUG org.jacorb.orb.giop - created
> org.omg.ETF.Factories: org.jacorb.orb.iiop.IIOPFactories
> 2015-05-26 14:21:28,934 [main] INFO org.jacorb.orb.giop -
> ClientConnectionManager: created new ClientGIOPConnection to
> bruatfpd111.iggroup.local:5353 (7e0ac1b1)
> 2015-05-26 14:21:28,934 [main] DEBUG org.jacorb.util.tpool - [0/0]
> creating new thread
> 2015-05-26 14:21:28,934 [ClientMessageReceptor0] DEBUG
> org.jacorb.util.tpool - [0/1] removed idle thread (job scheduled)
> 2015-05-26 14:21:28,934 [ClientMessageReceptor0] DEBUG
> org.jacorb.giop.conn - ClientGIOPConnection to
> bruatfpd111.iggroup.local:5353 (7e0ac1b1): will wait until connected
> 2015-05-26 14:21:28,934 [main] DEBUG org.jacorb.orb.delegate - Adding
> new retry group for bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,934 [main] DEBUG org.jacorb.giop.conn -
> GIOPConnection.sendMessage timeout (millis): 0
> 2015-05-26 14:21:28,934 [main] DEBUG org.jacorb.giop.conn -
> ClientGIOPConnection to bruatfpd111.iggroup.local:5353 (7e0ac1b1):
> sendMessage() - opening transport
> org.jacorb.orb.iiop.ClientIIOPConnection at 7931d9dc
> 2015-05-26 14:21:28,934 [main] DEBUG org.jacorb.orb.factory - created
> SocketFactory: org.jacorb.orb.factory.DefaultSocketFactory
> 2015-05-26 14:21:28,934 [main] DEBUG org.jacorb.orb.iiop.ClientIIOPConnection - Trying to connect to bruatfpd111.iggroup.local:5353 with timeout=90000.
> 2015-05-26 14:21:28,934 [main] INFO
> org.jacorb.orb.iiop.ClientIIOPConnection - Connected to
> bruatfpd111.iggroup.local:5353 from local port 52507
> 2015-05-26 14:21:28,949 [main] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - wrote 12 bytes to
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [main] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - wrote 36 bytes to
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [main] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - wrote 87 bytes to
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [main] DEBUG org.jacorb.giop.conn - wrote GIOP
> message of size 103 to ClientGIOPConnection to
> bruatfpd111.iggroup.local:5353 (7e0ac1b1)
> 2015-05-26 14:21:28,949 [ClientMessageReceptor0] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - read 12 bytes from
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [ClientMessageReceptor0] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - read 282 bytes from
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [ClientMessageReceptor0] DEBUG
> org.jacorb.giop.conn - read GIOP message of size 294 from
> ClientGIOPConnection to bruatfpd111.iggroup.local:5353 (7e0ac1b1)
> 2015-05-26 14:21:28,949 [main] DEBUG org.jacorb.orb.giop -
> ClientConnectionManager: releasing ClientGIOPConnection to
> bruatfpd111.iggroup.local:5353 (7e0ac1b1)
> 2015-05-26 14:21:28,949 [main] DEBUG org.jacorb.giop.conn -
> ClientGIOPConnection to bruatfpd111.iggroup.local:5353 (7e0ac1b1):
> close()
> 2015-05-26 14:21:28,949 [main] INFO org.jacorb.orb.iiop.ClientIIOPConnection - Client-side TCP transport to bruatfpd111.iggroup.local:5353 closed.
> 2015-05-26 14:21:28,949 [main] INFO org.jacorb.orb.giop -
> ClientConnectionManager: created new ClientGIOPConnection to
> bruatfpd111.iggroup.local:5353 (41ce616c)
> 2015-05-26 14:21:28,949 [main] DEBUG org.jacorb.util.tpool - [0/1]
> creating new thread
> 2015-05-26 14:21:28,949 [ClientMessageReceptor0] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - Transport to
> bruatfpd111.iggroup.local:5353: stream closed Socket closed
> 2015-05-26 14:21:28,949 [ClientMessageReceptor1] DEBUG
> org.jacorb.util.tpool - [0/2] removed idle thread (job scheduled)
> 2015-05-26 14:21:28,949 [ClientMessageReceptor1] DEBUG
> org.jacorb.giop.conn - ClientGIOPConnection to
> bruatfpd111.iggroup.local:5353 (41ce616c): will wait until connected
> 2015-05-26 14:21:28,949 [main] INFO org.jacorb.giop.conn - Negotiated
> char codeset of UTF8 and wchar of UTF16
> 2015-05-26 14:21:28,949 [main] DEBUG org.jacorb.giop.conn -
> GIOPConnection.sendMessage timeout (millis): 0
> 2015-05-26 14:21:28,949 [main] DEBUG org.jacorb.giop.conn -
> ClientGIOPConnection to bruatfpd111.iggroup.local:5353 (41ce616c):
> sendMessage() - opening transport
> org.jacorb.orb.iiop.ClientIIOPConnection at 5d09823a
> 2015-05-26 14:21:28,949 [main] DEBUG org.jacorb.orb.iiop.ClientIIOPConnection - Trying to connect to bruatfpd111.iggroup.local:5353 with timeout=90000.
> 2015-05-26 14:21:28,949 [main] INFO
> org.jacorb.orb.iiop.ClientIIOPConnection - Connected to
> bruatfpd111.iggroup.local:5353 from local port 52508
> 2015-05-26 14:21:28,949 [main] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - wrote 100 bytes to
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [main] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - wrote 28 bytes to
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [main] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - wrote 47 bytes to
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [main] DEBUG org.jacorb.giop.conn - wrote GIOP
> message of size 151 to ClientGIOPConnection to
> bruatfpd111.iggroup.local:5353 (41ce616c)
> 2015-05-26 14:21:28,949 [ClientMessageReceptor1] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - read 12 bytes from
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [ClientMessageReceptor1] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - read 13 bytes from
> bruatfpd111.iggroup.local:5353
> 2015-05-26 14:21:28,949 [ClientMessageReceptor1] DEBUG
> org.jacorb.giop.conn - read GIOP message of size 25 from
> ClientGIOPConnection to bruatfpd111.iggroup.local:5353 (41ce616c)
> 2015-05-26 14:21:28,949 [main] DEBUG NamingServiceUtil - Got New Root Context.
>
> ...
>
> Sometime later this socket close is reported as COMM_FAILURE at DEBUG level, though as of JacORB 3.6.1 this does not cause an "ERROR" (in JacORB 3.6 it's an ERROR).
>
> 2015-05-26 14:21:29,090 [ClientMessageReceptor0] DEBUG
> org.jacorb.orb.iiop.ClientIIOPConnection - to_COMM_FAILURE: Caught
> exception
> java.net.SocketException: Socket closed at
> java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.7.0_76]
> at java.net.SocketInputStream.read(Unknown Source) ~[na:1.7.0_76] at
> java.net.SocketInputStream.read(Unknown Source) ~[na:1.7.0_76] at
> org.jacorb.orb.etf.StreamConnectionBase.read(StreamConnectionBase.java
> :111) ~[na:3.6.1] at
> org.jacorb.orb.giop.GIOPConnection.getMessage(GIOPConnection.java:388)
> [na:3.6.1] at
> org.jacorb.orb.giop.GIOPConnection.receiveMessagesLoop(GIOPConnection.
> java:548) [na:3.6.1] at
> org.jacorb.orb.giop.GIOPConnection.receiveMessages(GIOPConnection.java
> :535) [na:3.6.1] at
> org.jacorb.orb.giop.MessageReceptor.doWork(MessageReceptor.java:69)
> [na:3.6.1] at
> org.jacorb.util.threadpool.ConsumerTie.run(ConsumerTie.java:60)
> [na:3.6.1] at java.lang.Thread.run(Unknown Source) [na:1.7.0_76]
>
> David Gibbs
> Technical Manager
>
> IG, Cannon Bridge House
> 25 Dowgate Hill London EC4R 2YA
> D: +442075730697 | T: +442078960011
>
> www.igmarkets.com
>
> CREATING OPPORTUNITY
> CFDs | SPREAD BETTING | FX
> The information contained in this email is strictly confidential and for the use of the addressee only, unless otherwise indicated. If you are not the intended recipient, please do not read, copy, use or disclose to others this message or any attachment. Please also notify the sender by replying to this email or by telephone (+44(020 7896 0011) and then delete the email and any copies of it. Opinions, conclusion (etc) that do not relate to the official business of this company shall be understood as neither given nor endorsed by it. IG is a trading name of IG Markets Limited (a company registered in England and Wales, company number 04008957) and IG Index Limited (a company registered in England and Wales, company number 01190902). Registered address at Cannon Bridge House, 25 Dowgate Hill, London EC4R 2YA. Both IG Markets Limited (register number 195355) and IG Index Limited (register number 114059) are authorised and regulated by the Financial Conduct Authority.
> _______________________________________________
> jacorb-developer maillist -
> jacorb-developer at lists.spline.inf.fu-berlin.de
> https://lists.spline.inf.fu-berlin.de/mailman/listinfo/jacorb-develope
> r
--
Phil Mesnier
Principal Software Engineer and Partner, http://www.ociweb.com
Object Computing, Inc. +01.314.579.0066 x225
More information about the jacorb-developer
mailing list