2013-06-17 14:05:30,467 DEBUG [ServerMessageReceptor2] (RequestQueue.java:144) - rid: 2 opname: bind is queued (queue size: 1) 2013-06-17 14:05:30,468 DEBUG [RequestController-2] (RequestController.java:336) - rid: 2 opname: bind trying to get a RequestProcessor 2013-06-17 14:05:30,468 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:30,468 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 2 opname: bind starts with request processing 2013-06-17 14:05:30,468 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 2 opname: bind invokeOperation on servant (stream based) 2013-06-17 14:05:30,468 INFO [RequestProcessor-5] (NamingContextImpl.java:145) - Bound name: sas\/cogen\/externe\/ConnecteurFichier.Service 2013-06-17 14:05:30,468 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to bind 2013-06-17 14:05:30,468 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:30,468 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 24 bytes to hampton.devci.net:50598 2013-06-17 14:05:30,469 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 24 to ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,469 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 2 opname: bind ends with request processing 2013-06-17 14:05:30,470 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 12 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,471 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 204 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,471 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,471 DEBUG [ServerMessageReceptor2] (POA.java:507) - POA NameServer-POA rid: 4 opname: resolve _invoke: queuing request 2013-06-17 14:05:30,471 DEBUG [ServerMessageReceptor2] (RequestQueue.java:144) - rid: 4 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:30,471 DEBUG [RequestController-2] (RequestController.java:336) - rid: 4 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:30,471 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:30,472 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 4 opname: resolve starts with request processing 2013-06-17 14:05:30,472 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 4 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:30,472 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:30,472 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:30,472 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 200 bytes to hampton.devci.net:50598 2013-06-17 14:05:30,472 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,472 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 4 opname: resolve ends with request processing 2013-06-17 14:05:30,480 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 12 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,480 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 224 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,480 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,481 DEBUG [ServerMessageReceptor2] (POA.java:507) - POA NameServer-POA rid: 6 opname: resolve _invoke: queuing request 2013-06-17 14:05:30,481 DEBUG [ServerMessageReceptor2] (RequestQueue.java:144) - rid: 6 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:30,481 DEBUG [RequestController-2] (RequestController.java:336) - rid: 6 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:30,481 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:30,481 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 6 opname: resolve starts with request processing 2013-06-17 14:05:30,481 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 6 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:30,481 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:30,481 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:30,481 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to hampton.devci.net:50598 2013-06-17 14:05:30,482 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,482 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 6 opname: resolve ends with request processing 2013-06-17 14:05:30,520 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 12 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,520 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 224 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,521 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,521 DEBUG [ServerMessageReceptor2] (POA.java:507) - POA NameServer-POA rid: 8 opname: resolve _invoke: queuing request 2013-06-17 14:05:30,521 DEBUG [ServerMessageReceptor2] (RequestQueue.java:144) - rid: 8 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:30,521 DEBUG [RequestController-2] (RequestController.java:336) - rid: 8 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:30,521 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:30,521 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 8 opname: resolve starts with request processing 2013-06-17 14:05:30,521 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 8 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:30,521 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:30,522 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:30,522 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to hampton.devci.net:50598 2013-06-17 14:05:30,522 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,522 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 8 opname: resolve ends with request processing 2013-06-17 14:05:30,554 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 12 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,554 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 224 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,554 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,554 DEBUG [ServerMessageReceptor2] (POA.java:507) - POA NameServer-POA rid: 10 opname: resolve _invoke: queuing request 2013-06-17 14:05:30,554 DEBUG [ServerMessageReceptor2] (RequestQueue.java:144) - rid: 10 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:30,555 DEBUG [RequestController-2] (RequestController.java:336) - rid: 10 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:30,555 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:30,555 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 10 opname: resolve starts with request processing 2013-06-17 14:05:30,555 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 10 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:30,555 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:30,555 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:30,555 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to hampton.devci.net:50598 2013-06-17 14:05:30,555 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,556 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 10 opname: resolve ends with request processing 2013-06-17 14:05:30,568 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 12 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,568 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 224 bytes from hampton.devci.net:50598 2013-06-17 14:05:30,568 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,568 DEBUG [ServerMessageReceptor2] (POA.java:507) - POA NameServer-POA rid: 12 opname: resolve _invoke: queuing request 2013-06-17 14:05:30,568 DEBUG [ServerMessageReceptor2] (RequestQueue.java:144) - rid: 12 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:30,569 DEBUG [RequestController-2] (RequestController.java:336) - rid: 12 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:30,569 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:30,569 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 12 opname: resolve starts with request processing 2013-06-17 14:05:30,569 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 12 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:30,569 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:30,569 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:30,569 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to hampton.devci.net:50598 2013-06-17 14:05:30,569 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc) 2013-06-17 14:05:30,569 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 12 opname: resolve ends with request processing 2013-06-17 14:05:32,061 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,061 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,061 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,062 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 224 opname: resolve _invoke: queuing request 2013-06-17 14:05:32,062 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 224 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:32,062 DEBUG [RequestController-2] (RequestController.java:336) - rid: 224 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:32,063 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:32,063 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 224 opname: resolve starts with request processing 2013-06-17 14:05:32,064 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 224 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:32,064 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:32,064 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:32,064 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,064 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,064 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 224 opname: resolve ends with request processing 2013-06-17 14:05:32,320 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,320 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 192 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,321 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 204 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,321 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 226 opname: resolve _invoke: queuing request 2013-06-17 14:05:32,321 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 226 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:32,321 DEBUG [RequestController-2] (RequestController.java:336) - rid: 226 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:32,321 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:32,321 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 226 opname: resolve starts with request processing 2013-06-17 14:05:32,321 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 226 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:32,322 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:32,322 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:32,322 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,322 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,322 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 226 opname: resolve ends with request processing 2013-06-17 14:05:32,369 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,369 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 196 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,369 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 208 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,369 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 228 opname: resolve _invoke: queuing request 2013-06-17 14:05:32,369 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 228 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:32,370 DEBUG [RequestController-2] (RequestController.java:336) - rid: 228 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:32,370 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:32,370 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 228 opname: resolve starts with request processing 2013-06-17 14:05:32,370 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 228 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:32,370 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:32,370 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:32,370 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,370 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,371 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 228 opname: resolve ends with request processing 2013-06-17 14:05:32,507 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,507 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 208 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,507 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 220 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,508 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 230 opname: resolve _invoke: queuing request 2013-06-17 14:05:32,508 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 230 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:32,508 DEBUG [RequestController-2] (RequestController.java:336) - rid: 230 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:32,508 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:32,508 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 230 opname: resolve starts with request processing 2013-06-17 14:05:32,508 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 230 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:32,508 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:32,508 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:32,508 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 220 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,509 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 220 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,509 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 230 opname: resolve ends with request processing 2013-06-17 14:05:32,636 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,636 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 208 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,636 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 220 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,637 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 232 opname: resolve _invoke: queuing request 2013-06-17 14:05:32,637 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 232 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:32,637 DEBUG [RequestController-2] (RequestController.java:336) - rid: 232 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:32,637 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:32,637 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 232 opname: resolve starts with request processing 2013-06-17 14:05:32,637 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 232 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:32,637 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:32,637 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:32,638 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 220 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:32,638 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 220 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:32,638 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 232 opname: resolve ends with request processing 2013-06-17 14:05:50,916 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:50,916 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:50,916 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:50,917 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 234 opname: resolve _invoke: queuing request 2013-06-17 14:05:50,917 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 234 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:50,917 DEBUG [RequestController-2] (RequestController.java:336) - rid: 234 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:50,917 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:50,917 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 234 opname: resolve starts with request processing 2013-06-17 14:05:50,917 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 234 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:50,918 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:50,918 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:50,918 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:50,918 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:50,918 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 234 opname: resolve ends with request processing 2013-06-17 14:05:50,940 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:50,940 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 196 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:50,940 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 208 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:50,940 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 236 opname: resolve _invoke: queuing request 2013-06-17 14:05:50,940 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 236 opname: resolve is queued (queue size: 1) 2013-06-17 14:05:50,940 DEBUG [RequestController-2] (RequestController.java:336) - rid: 236 opname: resolve trying to get a RequestProcessor 2013-06-17 14:05:50,941 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:05:50,941 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 236 opname: resolve starts with request processing 2013-06-17 14:05:50,941 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 236 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:05:50,941 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:05:50,941 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:05:50,941 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:05:50,941 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:05:50,941 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 236 opname: resolve ends with request processing 2013-06-17 14:06:30,377 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:06:30,377 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:06:30,378 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:06:30,378 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 238 opname: resolve _invoke: queuing request 2013-06-17 14:06:30,378 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 238 opname: resolve is queued (queue size: 1) 2013-06-17 14:06:30,378 DEBUG [RequestController-2] (RequestController.java:336) - rid: 238 opname: resolve trying to get a RequestProcessor 2013-06-17 14:06:30,379 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:06:30,379 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 238 opname: resolve starts with request processing 2013-06-17 14:06:30,379 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 238 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:06:30,379 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:06:30,379 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:06:30,379 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:06:30,379 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:06:30,379 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 238 opname: resolve ends with request processing 2013-06-17 14:06:30,388 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:06:30,388 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:06:30,388 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:06:30,389 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 240 opname: resolve _invoke: queuing request 2013-06-17 14:06:30,389 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 240 opname: resolve is queued (queue size: 1) 2013-06-17 14:06:30,389 DEBUG [RequestController-2] (RequestController.java:336) - rid: 240 opname: resolve trying to get a RequestProcessor 2013-06-17 14:06:30,389 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:06:30,389 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 240 opname: resolve starts with request processing 2013-06-17 14:06:30,389 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 240 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:06:30,389 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:06:30,389 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:06:30,390 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:06:30,390 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:06:30,390 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 240 opname: resolve ends with request processing 2013-06-17 14:07:00,397 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:00,397 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:00,397 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:00,398 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 242 opname: resolve _invoke: queuing request 2013-06-17 14:07:00,398 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 242 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:00,398 DEBUG [RequestController-2] (RequestController.java:336) - rid: 242 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:00,398 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:00,398 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 242 opname: resolve starts with request processing 2013-06-17 14:07:00,398 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 242 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:00,398 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:00,398 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:00,399 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:00,399 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:00,399 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 242 opname: resolve ends with request processing 2013-06-17 14:07:00,406 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:00,406 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:00,406 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:00,406 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 244 opname: resolve _invoke: queuing request 2013-06-17 14:07:00,406 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 244 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:00,406 DEBUG [RequestController-2] (RequestController.java:336) - rid: 244 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:00,406 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:00,407 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 244 opname: resolve starts with request processing 2013-06-17 14:07:00,407 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 244 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:00,407 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:00,407 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:00,407 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:00,407 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:00,407 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 244 opname: resolve ends with request processing 2013-06-17 14:07:15,644 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:135) - Transport to hampton.devci.net:50598: stream closed Connection reset 2013-06-17 14:07:15,645 DEBUG [ServerMessageReceptor2] (SSLListenerUtil.java:162) - Unknown exception type java.net.SocketException with exception java.net.SocketException: Connection reset 2013-06-17 14:07:15,645 DEBUG [ServerMessageReceptor2] (ConnectionBase.java:148) - to_COMM_FAILURE: Caught exception java.net.SocketException: Connection reset at java.net.SocketInputStream.read(SocketInputStream.java:189) at java.net.SocketInputStream.read(SocketInputStream.java:121) at org.jacorb.orb.etf.StreamConnectionBase.read(StreamConnectionBase.java:110) at org.jacorb.orb.giop.GIOPConnection.getMessage(GIOPConnection.java:380) at org.jacorb.orb.giop.GIOPConnection.receiveMessagesLoop(GIOPConnection.java:538) at org.jacorb.orb.giop.GIOPConnection.receiveMessages(GIOPConnection.java:527) at org.jacorb.orb.giop.MessageReceptor.doWork(MessageReceptor.java:69) at org.jacorb.util.threadpool.ConsumerTie.run(ConsumerTie.java:60) at java.lang.Thread.run(Thread.java:722) 2013-06-17 14:07:15,649 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:394) - ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc): getMessage() -- COMM_FAILURE 2013-06-17 14:07:15,649 DEBUG [ServerMessageReceptor2] (ServerGIOPConnection.java:227) - ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc): streamClosed() 2013-06-17 14:07:15,649 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:1129) - ServerGIOPConnection to hampton.devci.net:50598 from [kelowna.elt.fr.ds.corp:14200] (65a503bc): close() 2013-06-17 14:07:15,650 INFO [ServerMessageReceptor2] (ServerIIOPConnection.java:136) - Closed server-side transport to hampton.devci.net:50598 2013-06-17 14:07:15,650 DEBUG [ServerMessageReceptor2] (ThreadPool.java:111) - [1/3] job queue empty 2013-06-17 14:07:21,054 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,054 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 152 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,055 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 164 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,055 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 246 opname: list _invoke: queuing request 2013-06-17 14:07:21,055 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 246 opname: list is queued (queue size: 1) 2013-06-17 14:07:21,055 DEBUG [RequestController-2] (RequestController.java:336) - rid: 246 opname: list trying to get a RequestProcessor 2013-06-17 14:07:21,056 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,057 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 246 opname: list starts with request processing 2013-06-17 14:07:21,057 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 246 opname: list invokeOperation on servant (stream based) 2013-06-17 14:07:21,057 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to list 2013-06-17 14:07:21,057 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,057 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 3428 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,060 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 3428 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,061 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 246 opname: list ends with request processing 2013-06-17 14:07:21,062 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,062 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 220 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,062 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 232 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,062 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 248 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,062 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 248 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,063 DEBUG [RequestController-2] (RequestController.java:336) - rid: 248 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,063 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,063 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 248 opname: resolve starts with request processing 2013-06-17 14:07:21,063 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 248 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,063 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,063 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,063 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,064 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,064 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 248 opname: resolve ends with request processing 2013-06-17 14:07:21,065 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,065 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 208 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,065 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 220 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,066 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 250 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,066 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 250 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,066 DEBUG [RequestController-2] (RequestController.java:336) - rid: 250 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,066 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,066 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 250 opname: resolve starts with request processing 2013-06-17 14:07:21,066 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 250 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,066 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,066 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,066 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 220 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,067 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 220 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,067 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 250 opname: resolve ends with request processing 2013-06-17 14:07:21,068 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,068 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 208 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,068 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 220 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,068 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 252 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,068 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 252 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,068 DEBUG [RequestController-2] (RequestController.java:336) - rid: 252 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,068 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,069 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 252 opname: resolve starts with request processing 2013-06-17 14:07:21,069 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 252 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,069 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,069 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,069 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,069 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,069 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 252 opname: resolve ends with request processing 2013-06-17 14:07:21,076 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,076 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 220 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,076 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 232 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,076 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 254 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,077 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 254 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,077 DEBUG [RequestController-2] (RequestController.java:336) - rid: 254 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,077 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,077 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 254 opname: resolve starts with request processing 2013-06-17 14:07:21,077 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 254 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,077 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,077 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,077 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,078 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,078 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 254 opname: resolve ends with request processing 2013-06-17 14:07:21,079 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,079 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,079 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,079 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 256 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,079 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 256 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,080 DEBUG [RequestController-2] (RequestController.java:336) - rid: 256 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,080 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,080 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 256 opname: resolve starts with request processing 2013-06-17 14:07:21,080 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 256 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,080 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,080 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,080 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 220 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,080 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 220 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,081 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 256 opname: resolve ends with request processing 2013-06-17 14:07:21,084 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,084 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 220 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,084 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 232 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,084 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 258 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,084 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 258 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,084 DEBUG [RequestController-2] (RequestController.java:336) - rid: 258 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,085 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,085 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 258 opname: resolve starts with request processing 2013-06-17 14:07:21,085 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 258 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,085 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,085 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,085 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,085 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,085 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 258 opname: resolve ends with request processing 2013-06-17 14:07:21,087 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,087 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 196 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,087 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 208 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,087 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 260 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,087 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 260 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,088 DEBUG [RequestController-2] (RequestController.java:336) - rid: 260 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,088 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,088 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 260 opname: resolve starts with request processing 2013-06-17 14:07:21,088 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 260 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,088 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,088 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,088 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,089 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,089 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 260 opname: resolve ends with request processing 2013-06-17 14:07:21,090 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,090 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,090 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,090 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 262 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,090 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 262 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,090 DEBUG [RequestController-2] (RequestController.java:336) - rid: 262 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,091 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,091 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 262 opname: resolve starts with request processing 2013-06-17 14:07:21,091 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 262 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,091 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,091 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,091 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,091 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,091 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 262 opname: resolve ends with request processing 2013-06-17 14:07:21,093 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,093 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 212 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,093 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 224 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,093 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 264 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,093 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 264 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,093 DEBUG [RequestController-2] (RequestController.java:336) - rid: 264 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,093 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,094 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 264 opname: resolve starts with request processing 2013-06-17 14:07:21,094 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 264 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,094 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,094 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,094 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,094 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,094 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 264 opname: resolve ends with request processing 2013-06-17 14:07:21,095 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,095 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 208 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,095 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 220 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,096 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 266 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,096 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 266 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,096 DEBUG [RequestController-2] (RequestController.java:336) - rid: 266 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,096 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,096 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 266 opname: resolve starts with request processing 2013-06-17 14:07:21,096 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 266 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,096 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,097 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,097 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 212 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,097 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 212 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,097 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 266 opname: resolve ends with request processing 2013-06-17 14:07:21,098 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,098 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 184 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,098 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 196 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,098 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 268 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,098 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 268 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,099 DEBUG [RequestController-2] (RequestController.java:336) - rid: 268 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,099 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,099 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 268 opname: resolve starts with request processing 2013-06-17 14:07:21,099 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 268 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,099 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,099 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,099 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,099 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,100 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 268 opname: resolve ends with request processing 2013-06-17 14:07:21,101 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,101 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 212 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,101 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 224 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,101 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 270 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,101 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 270 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,102 DEBUG [RequestController-2] (RequestController.java:336) - rid: 270 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,102 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,102 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 270 opname: resolve starts with request processing 2013-06-17 14:07:21,102 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 270 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,102 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,102 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,102 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,102 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,103 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 270 opname: resolve ends with request processing 2013-06-17 14:07:21,103 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,104 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,104 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,104 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 272 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,104 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 272 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,104 DEBUG [RequestController-2] (RequestController.java:336) - rid: 272 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,104 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,104 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 272 opname: resolve starts with request processing 2013-06-17 14:07:21,105 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 272 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,105 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,105 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,105 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,105 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,105 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 272 opname: resolve ends with request processing 2013-06-17 14:07:21,163 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,163 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 192 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,163 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 204 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,163 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 274 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,163 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 274 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,164 DEBUG [RequestController-2] (RequestController.java:336) - rid: 274 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,164 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,164 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 274 opname: resolve starts with request processing 2013-06-17 14:07:21,164 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 274 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,164 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,164 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,164 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 192 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,164 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 192 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,165 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 274 opname: resolve ends with request processing 2013-06-17 14:07:21,166 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,166 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,166 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,166 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 276 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,166 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 276 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,166 DEBUG [RequestController-2] (RequestController.java:336) - rid: 276 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,166 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,167 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 276 opname: resolve starts with request processing 2013-06-17 14:07:21,167 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 276 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,167 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,167 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,167 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,167 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,167 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 276 opname: resolve ends with request processing 2013-06-17 14:07:21,168 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,169 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,169 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,169 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 278 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,169 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 278 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,169 DEBUG [RequestController-2] (RequestController.java:336) - rid: 278 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,169 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,170 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 278 opname: resolve starts with request processing 2013-06-17 14:07:21,170 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 278 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,170 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,170 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,170 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,170 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,170 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 278 opname: resolve ends with request processing 2013-06-17 14:07:21,172 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,172 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 212 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,172 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 224 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,172 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 280 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,172 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 280 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,172 DEBUG [RequestController-2] (RequestController.java:336) - rid: 280 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,172 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,173 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 280 opname: resolve starts with request processing 2013-06-17 14:07:21,173 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 280 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,173 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,173 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,173 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 216 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,173 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 216 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,173 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 280 opname: resolve ends with request processing 2013-06-17 14:07:21,174 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,174 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,174 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,175 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 282 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,175 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 282 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,175 DEBUG [RequestController-2] (RequestController.java:336) - rid: 282 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,175 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,175 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 282 opname: resolve starts with request processing 2013-06-17 14:07:21,175 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 282 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,175 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,175 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,176 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,176 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,176 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 282 opname: resolve ends with request processing 2013-06-17 14:07:21,177 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,177 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 236 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,177 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 248 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,178 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 284 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,178 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 284 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,178 DEBUG [RequestController-2] (RequestController.java:336) - rid: 284 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,178 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,178 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 284 opname: resolve starts with request processing 2013-06-17 14:07:21,178 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 284 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 284 opname: resolve ends with request processing 2013-06-17 14:07:21,179 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,179 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,179 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,179 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 286 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,179 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 286 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,179 DEBUG [RequestController-2] (RequestController.java:336) - rid: 286 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,179 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 286 opname: resolve starts with request processing 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 286 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,179 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 286 opname: resolve ends with request processing 2013-06-17 14:07:21,183 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,183 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,183 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,184 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 288 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,184 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 288 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,184 DEBUG [RequestController-2] (RequestController.java:336) - rid: 288 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,184 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,184 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 288 opname: resolve starts with request processing 2013-06-17 14:07:21,184 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 288 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,184 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,184 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,184 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,185 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,185 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 288 opname: resolve ends with request processing 2013-06-17 14:07:21,185 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,186 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 220 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,186 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 232 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,186 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 290 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,186 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 290 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,186 DEBUG [RequestController-2] (RequestController.java:336) - rid: 290 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,186 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,187 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 290 opname: resolve starts with request processing 2013-06-17 14:07:21,187 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 290 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,187 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,187 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,187 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,187 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,187 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 290 opname: resolve ends with request processing 2013-06-17 14:07:21,188 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,188 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,189 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,189 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 292 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,189 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 292 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,193 DEBUG [RequestController-2] (RequestController.java:336) - rid: 292 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,194 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,194 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 292 opname: resolve starts with request processing 2013-06-17 14:07:21,194 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 292 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,194 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,194 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,194 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,194 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,195 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 292 opname: resolve ends with request processing 2013-06-17 14:07:21,196 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,196 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 212 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,196 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 224 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,197 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 294 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,197 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 294 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,197 DEBUG [RequestController-2] (RequestController.java:336) - rid: 294 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,197 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,197 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 294 opname: resolve starts with request processing 2013-06-17 14:07:21,197 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 294 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,197 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,197 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,198 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 216 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,198 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 216 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,198 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 294 opname: resolve ends with request processing 2013-06-17 14:07:21,206 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,206 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 188 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,206 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 200 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,206 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 296 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,206 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 296 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,207 DEBUG [RequestController-2] (RequestController.java:336) - rid: 296 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,207 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,207 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 296 opname: resolve starts with request processing 2013-06-17 14:07:21,207 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 296 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,207 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,207 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,207 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 196 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,207 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 196 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,208 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 296 opname: resolve ends with request processing 2013-06-17 14:07:21,209 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,209 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,209 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,209 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 298 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,209 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 298 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,209 DEBUG [RequestController-2] (RequestController.java:336) - rid: 298 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,209 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,210 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 298 opname: resolve starts with request processing 2013-06-17 14:07:21,210 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 298 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,211 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,211 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,211 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 212 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,211 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 212 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,211 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 298 opname: resolve ends with request processing 2013-06-17 14:07:21,212 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,212 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 188 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,213 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 200 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,213 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 300 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,213 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 300 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,213 DEBUG [RequestController-2] (RequestController.java:336) - rid: 300 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,213 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,213 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 300 opname: resolve starts with request processing 2013-06-17 14:07:21,213 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 300 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,214 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,214 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,214 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 216 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,214 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 216 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,214 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 300 opname: resolve ends with request processing 2013-06-17 14:07:21,217 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,218 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 232 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,218 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 244 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,218 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 302 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,218 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 302 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,218 DEBUG [RequestController-2] (RequestController.java:336) - rid: 302 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,218 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,218 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 302 opname: resolve starts with request processing 2013-06-17 14:07:21,218 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 302 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,219 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,219 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,219 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,219 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,219 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 302 opname: resolve ends with request processing 2013-06-17 14:07:21,225 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,225 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 196 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,226 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 208 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,226 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 304 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,226 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 304 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,226 DEBUG [RequestController-2] (RequestController.java:336) - rid: 304 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,226 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,226 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 304 opname: resolve starts with request processing 2013-06-17 14:07:21,226 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 304 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,226 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,227 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,227 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 196 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,227 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 196 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,227 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 304 opname: resolve ends with request processing 2013-06-17 14:07:21,228 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,228 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 240 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,228 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 252 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,228 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 306 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,228 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 306 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,228 DEBUG [RequestController-2] (RequestController.java:336) - rid: 306 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,228 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,229 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 306 opname: resolve starts with request processing 2013-06-17 14:07:21,229 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 306 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,229 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,229 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,229 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 216 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,229 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 216 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,229 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 306 opname: resolve ends with request processing 2013-06-17 14:07:21,237 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,237 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 196 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,237 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 208 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,237 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 308 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,237 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 308 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,238 DEBUG [RequestController-2] (RequestController.java:336) - rid: 308 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,238 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,238 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 308 opname: resolve starts with request processing 2013-06-17 14:07:21,238 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 308 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,238 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,238 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,238 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,238 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,238 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 308 opname: resolve ends with request processing 2013-06-17 14:07:21,239 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,239 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 196 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,239 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 208 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,240 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 310 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,240 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 310 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,240 DEBUG [RequestController-2] (RequestController.java:336) - rid: 310 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,240 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,240 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 310 opname: resolve starts with request processing 2013-06-17 14:07:21,240 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 310 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,240 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,240 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,240 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,241 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,241 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 310 opname: resolve ends with request processing 2013-06-17 14:07:21,242 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,242 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,242 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,242 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 312 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,242 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 312 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,242 DEBUG [RequestController-2] (RequestController.java:336) - rid: 312 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,242 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,243 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 312 opname: resolve starts with request processing 2013-06-17 14:07:21,243 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 312 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,243 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,243 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,243 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,243 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,243 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 312 opname: resolve ends with request processing 2013-06-17 14:07:21,244 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,245 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,245 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,245 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 314 opname: resolve _invoke: queuing request 2013-06-17 14:07:21,245 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 314 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:21,245 DEBUG [RequestController-2] (RequestController.java:336) - rid: 314 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:21,245 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:21,245 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 314 opname: resolve starts with request processing 2013-06-17 14:07:21,245 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 314 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:21,246 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:21,246 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:21,246 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:21,246 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:21,246 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 314 opname: resolve ends with request processing 2013-06-17 14:07:24,237 INFO [ServerSocketListener] (ServerIIOPConnection.java:79) - Opened new server-side TCP/IP transport to hampton.devci.net:50896 2013-06-17 14:07:24,237 DEBUG [ServerSocketListener] (GIOPConnectionManager.java:169) - GIOPConnectionManager: created new ServerGIOPConnection to hampton.devci.net:50896 from [kelowna.elt.fr.ds.corp:14200] (77d05385) 2013-06-17 14:07:24,238 DEBUG [ServerMessageReceptor2] (ThreadPool.java:131) - [0/3] removed idle thread (job scheduled) 2013-06-17 14:07:24,238 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 12 bytes from hampton.devci.net:50896 2013-06-17 14:07:24,238 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 172 bytes from hampton.devci.net:50896 2013-06-17 14:07:24,238 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:492) - read GIOP message of size 184 from ServerGIOPConnection to hampton.devci.net:50896 from [kelowna.elt.fr.ds.corp:14200] (77d05385) 2013-06-17 14:07:24,238 DEBUG [ServerMessageReceptor2] (ServerRequestListener.java:138) - Received CodeSetContext. Using ISO8859_1 as TCS and UTF16 as TCSW 2013-06-17 14:07:24,238 DEBUG [ServerMessageReceptor2] (POA.java:507) - POA NameServer-POA rid: 0 opname: _non_existent _invoke: queuing request 2013-06-17 14:07:24,238 DEBUG [ServerMessageReceptor2] (RequestQueue.java:144) - rid: 0 opname: _non_existent is queued (queue size: 1) 2013-06-17 14:07:24,239 DEBUG [RequestController-2] (RequestController.java:336) - rid: 0 opname: _non_existent trying to get a RequestProcessor 2013-06-17 14:07:24,239 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:24,239 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 0 opname: _non_existent starts with request processing 2013-06-17 14:07:24,239 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 0 opname: _non_existent invokeOperation on servant (stream based) 2013-06-17 14:07:24,239 DEBUG [RequestProcessor-5] (ServerRequest.java:375) - ServerRequest: reply to _non_existent 2013-06-17 14:07:24,239 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:24,239 DEBUG [RequestProcessor-5] (StreamConnectionBase.java:197) - wrote 25 bytes to hampton.devci.net:50896 2013-06-17 14:07:24,239 DEBUG [RequestProcessor-5] (GIOPConnection.java:1065) - wrote GIOP message of size 25 to ServerGIOPConnection to hampton.devci.net:50896 from [kelowna.elt.fr.ds.corp:14200] (77d05385) 2013-06-17 14:07:24,240 DEBUG [RequestProcessor-5] (RequestProcessor.java:827) - rid: 0 opname: _non_existent ends with request processing 2013-06-17 14:07:24,247 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 12 bytes from hampton.devci.net:50896 2013-06-17 14:07:24,247 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:158) - read 380 bytes from hampton.devci.net:50896 2013-06-17 14:07:24,247 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:492) - read GIOP message of size 392 from ServerGIOPConnection to hampton.devci.net:50896 from [kelowna.elt.fr.ds.corp:14200] (77d05385) 2013-06-17 14:07:24,247 DEBUG [ServerMessageReceptor2] (POA.java:507) - POA NameServer-POA rid: 2 opname: bind _invoke: queuing request 2013-06-17 14:07:24,247 DEBUG [ServerMessageReceptor2] (RequestQueue.java:144) - rid: 2 opname: bind is queued (queue size: 1) 2013-06-17 14:07:24,247 DEBUG [RequestController-2] (RequestController.java:336) - rid: 2 opname: bind trying to get a RequestProcessor 2013-06-17 14:07:24,247 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:24,247 DEBUG [RequestProcessor-5] (RequestProcessor.java:808) - rid: 2 opname: bind starts with request processing 2013-06-17 14:07:24,248 DEBUG [RequestProcessor-5] (RequestProcessor.java:316) - rid: 2 opname: bind invokeOperation on servant (stream based) 2013-06-17 14:07:24,250 INFO [RequestProcessor-5] (ClientConnectionManager.java:130) - ClientConnectionManager: created new ClientGIOPConnection to hampton.devci.net:50596 (50317d82) 2013-06-17 14:07:24,250 DEBUG [RequestProcessor-5] (ThreadPool.java:192) - [0/0] creating new thread 2013-06-17 14:07:24,250 DEBUG [RequestProcessor-5] (ORB.java:601) - findPOA: impl_name mismatch - NS_HAMPTON_null != StandardNS 2013-06-17 14:07:24,251 DEBUG [RequestProcessor-5] (ClientConnection.java:172) - No CodeSetComponentInfo in IOR. Will use default CodeSets 2013-06-17 14:07:24,251 DEBUG [RequestProcessor-5] (Delegate.java:1570) - Adding new retry group for hampton.devci.net:50596 2013-06-17 14:07:24,252 DEBUG [RequestProcessor-5] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:24,252 DEBUG [RequestProcessor-5] (GIOPConnection.java:1031) - ClientGIOPConnection to hampton.devci.net:50596 (50317d82): sendMessage() -- opening transportorg.jacorb.orb.iiop.ClientIIOPConnection@72e1c560 2013-06-17 14:07:24,253 DEBUG [RequestProcessor-5] (SocketFactoryManager.java:223) - created SocketFactory: org.jacorb.orb.factory.DefaultSocketFactory 2013-06-17 14:07:24,253 DEBUG [RequestProcessor-5] (ClientIIOPConnection.java:303) - Trying to connect to hampton.devci.net:50596 with timeout=90000. 2013-06-17 14:07:24,253 DEBUG [ClientMessageReceptor0] (ThreadPool.java:131) - [0/1] removed idle thread (job scheduled) 2013-06-17 14:07:30,417 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:30,417 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:30,417 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:30,418 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 316 opname: resolve _invoke: queuing request 2013-06-17 14:07:30,418 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 316 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:30,418 DEBUG [RequestController-2] (RequestController.java:336) - rid: 316 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:30,418 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:30,461 DEBUG [RequestProcessor-3] (RequestProcessor.java:808) - rid: 316 opname: resolve starts with request processing 2013-06-17 14:07:30,461 DEBUG [RequestProcessor-3] (RequestProcessor.java:316) - rid: 316 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:30,461 DEBUG [RequestProcessor-3] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:30,461 DEBUG [RequestProcessor-3] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:30,461 DEBUG [RequestProcessor-3] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:30,466 DEBUG [RequestProcessor-3] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:30,467 DEBUG [RequestProcessor-3] (RequestProcessor.java:827) - rid: 316 opname: resolve ends with request processing 2013-06-17 14:07:30,469 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:30,470 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:30,470 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:30,470 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 318 opname: resolve _invoke: queuing request 2013-06-17 14:07:30,470 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 318 opname: resolve is queued (queue size: 1) 2013-06-17 14:07:30,470 DEBUG [RequestController-2] (RequestController.java:336) - rid: 318 opname: resolve trying to get a RequestProcessor 2013-06-17 14:07:30,471 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:07:30,471 DEBUG [RequestProcessor-3] (RequestProcessor.java:808) - rid: 318 opname: resolve starts with request processing 2013-06-17 14:07:30,471 DEBUG [RequestProcessor-3] (RequestProcessor.java:316) - rid: 318 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:07:30,471 DEBUG [RequestProcessor-3] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:07:30,471 DEBUG [RequestProcessor-3] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:07:30,471 DEBUG [RequestProcessor-3] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:07:30,471 DEBUG [RequestProcessor-3] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:07:30,471 DEBUG [RequestProcessor-3] (RequestProcessor.java:827) - rid: 318 opname: resolve ends with request processing 2013-06-17 14:07:44,118 DEBUG [ServerMessageReceptor2] (StreamConnectionBase.java:135) - Transport to hampton.devci.net:50896: stream closed Connection reset 2013-06-17 14:07:44,119 DEBUG [ServerMessageReceptor2] (SSLListenerUtil.java:162) - Unknown exception type java.net.SocketException with exception java.net.SocketException: Connection reset 2013-06-17 14:07:44,119 DEBUG [ServerMessageReceptor2] (ConnectionBase.java:148) - to_COMM_FAILURE: Caught exception java.net.SocketException: Connection reset at java.net.SocketInputStream.read(SocketInputStream.java:189) at java.net.SocketInputStream.read(SocketInputStream.java:121) at org.jacorb.orb.etf.StreamConnectionBase.read(StreamConnectionBase.java:110) at org.jacorb.orb.giop.GIOPConnection.getMessage(GIOPConnection.java:380) at org.jacorb.orb.giop.GIOPConnection.receiveMessagesLoop(GIOPConnection.java:538) at org.jacorb.orb.giop.GIOPConnection.receiveMessages(GIOPConnection.java:527) at org.jacorb.orb.giop.MessageReceptor.doWork(MessageReceptor.java:69) at org.jacorb.util.threadpool.ConsumerTie.run(ConsumerTie.java:60) at java.lang.Thread.run(Thread.java:722) 2013-06-17 14:07:44,119 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:394) - ServerGIOPConnection to hampton.devci.net:50896 from [kelowna.elt.fr.ds.corp:14200] (77d05385): getMessage() -- COMM_FAILURE 2013-06-17 14:07:44,120 DEBUG [ServerMessageReceptor2] (ServerGIOPConnection.java:227) - ServerGIOPConnection to hampton.devci.net:50896 from [kelowna.elt.fr.ds.corp:14200] (77d05385): streamClosed() 2013-06-17 14:07:44,120 DEBUG [ServerMessageReceptor2] (GIOPConnection.java:1129) - ServerGIOPConnection to hampton.devci.net:50896 from [kelowna.elt.fr.ds.corp:14200] (77d05385): close() 2013-06-17 14:07:44,120 INFO [ServerMessageReceptor2] (ServerIIOPConnection.java:136) - Closed server-side transport to hampton.devci.net:50896 2013-06-17 14:07:44,120 DEBUG [ServerMessageReceptor2] (ThreadPool.java:111) - [1/3] job queue empty 2013-06-17 14:08:00,514 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:00,514 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:00,514 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:00,515 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 320 opname: resolve _invoke: queuing request 2013-06-17 14:08:00,515 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 320 opname: resolve is queued (queue size: 1) 2013-06-17 14:08:00,515 DEBUG [RequestController-2] (RequestController.java:336) - rid: 320 opname: resolve trying to get a RequestProcessor 2013-06-17 14:08:00,515 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:08:00,515 DEBUG [RequestProcessor-3] (RequestProcessor.java:808) - rid: 320 opname: resolve starts with request processing 2013-06-17 14:08:00,515 DEBUG [RequestProcessor-3] (RequestProcessor.java:316) - rid: 320 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:08:00,515 DEBUG [RequestProcessor-3] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:08:00,516 DEBUG [RequestProcessor-3] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:08:00,516 DEBUG [RequestProcessor-3] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:00,516 DEBUG [RequestProcessor-3] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:00,516 DEBUG [RequestProcessor-3] (RequestProcessor.java:827) - rid: 320 opname: resolve ends with request processing 2013-06-17 14:08:00,523 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:00,524 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:00,524 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:00,524 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 322 opname: resolve _invoke: queuing request 2013-06-17 14:08:00,524 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 322 opname: resolve is queued (queue size: 1) 2013-06-17 14:08:00,524 DEBUG [RequestController-2] (RequestController.java:336) - rid: 322 opname: resolve trying to get a RequestProcessor 2013-06-17 14:08:00,524 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:08:00,525 DEBUG [RequestProcessor-3] (RequestProcessor.java:808) - rid: 322 opname: resolve starts with request processing 2013-06-17 14:08:00,525 DEBUG [RequestProcessor-3] (RequestProcessor.java:316) - rid: 322 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:08:00,525 DEBUG [RequestProcessor-3] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:08:00,525 DEBUG [RequestProcessor-3] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:08:00,525 DEBUG [RequestProcessor-3] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:00,525 DEBUG [RequestProcessor-3] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:00,525 DEBUG [RequestProcessor-3] (RequestProcessor.java:827) - rid: 322 opname: resolve ends with request processing 2013-06-17 14:08:18,329 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:18,329 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:18,330 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:18,330 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 324 opname: resolve _invoke: queuing request 2013-06-17 14:08:18,330 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 324 opname: resolve is queued (queue size: 1) 2013-06-17 14:08:18,330 DEBUG [RequestController-2] (RequestController.java:336) - rid: 324 opname: resolve trying to get a RequestProcessor 2013-06-17 14:08:18,330 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:08:18,330 DEBUG [RequestProcessor-3] (RequestProcessor.java:808) - rid: 324 opname: resolve starts with request processing 2013-06-17 14:08:18,330 DEBUG [RequestProcessor-3] (RequestProcessor.java:316) - rid: 324 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:08:18,331 DEBUG [RequestProcessor-3] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:08:18,331 DEBUG [RequestProcessor-3] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:08:18,331 DEBUG [RequestProcessor-3] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:18,331 DEBUG [RequestProcessor-3] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:18,331 DEBUG [RequestProcessor-3] (RequestProcessor.java:827) - rid: 324 opname: resolve ends with request processing 2013-06-17 14:08:21,255 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:21,255 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:21,255 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:21,255 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 326 opname: unbind _invoke: queuing request 2013-06-17 14:08:21,255 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 326 opname: unbind is queued (queue size: 1) 2013-06-17 14:08:21,256 DEBUG [RequestController-2] (RequestController.java:336) - rid: 326 opname: unbind trying to get a RequestProcessor 2013-06-17 14:08:21,256 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:08:21,256 DEBUG [RequestProcessor-3] (RequestProcessor.java:808) - rid: 326 opname: unbind starts with request processing 2013-06-17 14:08:21,256 DEBUG [RequestProcessor-3] (RequestProcessor.java:316) - rid: 326 opname: unbind invokeOperation on servant (stream based) 2013-06-17 14:08:21,256 DEBUG [RequestProcessor-3] (ClientConnectionManager.java:160) - ClientConnectionManager: releasing ClientGIOPConnection to hampton.devci.net:50596 (50317d82) 2013-06-17 14:08:21,256 DEBUG [RequestProcessor-3] (GIOPConnection.java:1129) - ClientGIOPConnection to hampton.devci.net:50596 (50317d82): close() 2013-06-17 14:08:27,281 DEBUG [RequestProcessor-5] (ClientIIOPConnection.java:185) - Exception java.net.ConnectException: Connexion terminée par expiration du délai d'attente at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.jacorb.orb.factory.DefaultSocketFactory.doCreateSocket(DefaultSocketFactory.java:45) at org.jacorb.orb.factory.AbstractSocketFactory.createSocket(AbstractSocketFactory.java:60) at org.jacorb.orb.iiop.ClientIIOPConnection.createSocket(ClientIIOPConnection.java:314) at org.jacorb.orb.iiop.ClientIIOPConnection.connect(ClientIIOPConnection.java:149) at org.jacorb.orb.giop.GIOPConnection.sendMessage(GIOPConnection.java:1042) at org.jacorb.orb.giop.GIOPConnection.sendRequest(GIOPConnection.java:987) at org.jacorb.orb.giop.ClientConnection.sendRequest(ClientConnection.java:308) at org.jacorb.orb.giop.ClientConnection.sendRequest(ClientConnection.java:289) at org.jacorb.orb.Delegate._invoke_internal(Delegate.java:1335) at org.jacorb.orb.Delegate.invoke_internal(Delegate.java:1160) at org.jacorb.orb.Delegate.invoke(Delegate.java:1148) at org.jacorb.orb.Delegate.invokeBuiltin(Delegate.java:2039) at org.jacorb.orb.Delegate.non_existent(Delegate.java:1996) at org.omg.CORBA.portable.ObjectImpl._non_existent(ObjectImpl.java:61) at org.jacorb.naming.NamingContextImpl.isDead(NamingContextImpl.java:799) at org.jacorb.naming.NamingContextImpl.bind(NamingContextImpl.java:122) at org.omg.CosNaming.NamingContextExtPOA._invoke(NamingContextExtPOA.java:75) at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:348) at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:670) at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:820) 2013-06-17 14:08:27,282 INFO [RequestProcessor-5] (ClientIIOPConnection.java:194) - Retrying to connect to hampton.devci.net:50596 2013-06-17 14:08:27,784 DEBUG [RequestProcessor-5] (ClientIIOPConnection.java:303) - Trying to connect to hampton.devci.net:50596 with timeout=90000. 2013-06-17 14:08:30,573 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:30,574 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:30,574 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:30,574 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 328 opname: resolve _invoke: queuing request 2013-06-17 14:08:30,574 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 328 opname: resolve is queued (queue size: 1) 2013-06-17 14:08:30,574 DEBUG [RequestController-2] (RequestController.java:336) - rid: 328 opname: resolve trying to get a RequestProcessor 2013-06-17 14:08:30,574 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:08:30,575 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 328 opname: resolve starts with request processing 2013-06-17 14:08:30,575 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 328 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:08:30,575 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:08:30,575 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:08:30,575 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:30,575 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:30,575 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 328 opname: resolve ends with request processing 2013-06-17 14:08:30,584 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:30,584 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:30,585 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:30,585 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 330 opname: resolve _invoke: queuing request 2013-06-17 14:08:30,585 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 330 opname: resolve is queued (queue size: 1) 2013-06-17 14:08:30,585 DEBUG [RequestController-2] (RequestController.java:336) - rid: 330 opname: resolve trying to get a RequestProcessor 2013-06-17 14:08:30,585 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:08:30,585 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 330 opname: resolve starts with request processing 2013-06-17 14:08:30,585 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 330 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:08:30,585 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:08:30,586 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:08:30,586 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:08:30,586 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:08:30,586 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 330 opname: resolve ends with request processing 2013-06-17 14:09:00,640 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:00,640 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:00,640 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:00,641 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 332 opname: resolve _invoke: queuing request 2013-06-17 14:09:00,641 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 332 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:00,641 DEBUG [RequestController-2] (RequestController.java:336) - rid: 332 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:00,641 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:00,641 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 332 opname: resolve starts with request processing 2013-06-17 14:09:00,641 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 332 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:00,641 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:00,641 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:00,642 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:00,642 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:00,642 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 332 opname: resolve ends with request processing 2013-06-17 14:09:00,654 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:00,654 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:00,655 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:00,655 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 334 opname: resolve _invoke: queuing request 2013-06-17 14:09:00,655 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 334 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:00,655 DEBUG [RequestController-2] (RequestController.java:336) - rid: 334 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:00,655 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:00,655 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 334 opname: resolve starts with request processing 2013-06-17 14:09:00,655 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 334 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:00,655 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:00,656 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:00,656 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:00,656 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:00,656 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 334 opname: resolve ends with request processing 2013-06-17 14:09:21,332 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,332 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 212 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,332 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 224 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,333 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 336 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,333 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 336 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,333 DEBUG [RequestController-2] (RequestController.java:336) - rid: 336 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,333 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,333 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 336 opname: resolve starts with request processing 2013-06-17 14:09:21,333 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 336 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,333 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,333 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,334 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 216 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,334 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 216 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,334 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 336 opname: resolve ends with request processing 2013-06-17 14:09:21,339 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,339 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,339 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,339 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 338 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,339 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 338 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,339 DEBUG [RequestController-2] (RequestController.java:336) - rid: 338 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,339 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,340 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 338 opname: resolve starts with request processing 2013-06-17 14:09:21,340 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 338 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,340 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,340 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,340 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 212 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,340 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 212 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,340 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 338 opname: resolve ends with request processing 2013-06-17 14:09:21,343 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,343 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,343 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,343 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 340 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,343 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 340 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,343 DEBUG [RequestController-2] (RequestController.java:336) - rid: 340 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,344 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,347 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 340 opname: resolve starts with request processing 2013-06-17 14:09:21,347 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 340 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,347 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,348 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,348 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,348 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,348 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 340 opname: resolve ends with request processing 2013-06-17 14:09:21,352 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,352 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,352 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,352 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 342 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,352 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 342 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,353 DEBUG [RequestController-2] (RequestController.java:336) - rid: 342 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,353 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,353 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 342 opname: resolve starts with request processing 2013-06-17 14:09:21,353 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 342 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,353 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,353 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,353 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,353 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,353 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 342 opname: resolve ends with request processing 2013-06-17 14:09:21,354 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,355 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 192 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,355 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 204 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,355 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 344 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,355 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 344 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,355 DEBUG [RequestController-2] (RequestController.java:336) - rid: 344 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,355 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,355 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 344 opname: resolve starts with request processing 2013-06-17 14:09:21,355 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 344 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,356 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,356 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,356 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 192 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,356 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 192 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,356 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 344 opname: resolve ends with request processing 2013-06-17 14:09:21,357 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,357 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 192 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,357 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 204 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,357 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 346 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,357 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 346 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,358 DEBUG [RequestController-2] (RequestController.java:336) - rid: 346 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,358 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,358 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 346 opname: resolve starts with request processing 2013-06-17 14:09:21,358 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 346 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,358 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,358 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,358 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,358 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,359 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 346 opname: resolve ends with request processing 2013-06-17 14:09:21,361 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,361 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,361 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,362 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 348 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,362 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 348 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,362 DEBUG [RequestController-2] (RequestController.java:336) - rid: 348 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,362 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,362 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 348 opname: resolve starts with request processing 2013-06-17 14:09:21,362 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 348 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,362 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,362 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,362 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,363 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,363 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 348 opname: resolve ends with request processing 2013-06-17 14:09:21,364 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,364 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 216 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,364 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 228 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,376 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 350 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,376 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 350 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,377 DEBUG [RequestController-2] (RequestController.java:336) - rid: 350 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,377 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,377 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 350 opname: resolve starts with request processing 2013-06-17 14:09:21,377 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 350 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,377 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,377 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,377 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,377 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,378 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 350 opname: resolve ends with request processing 2013-06-17 14:09:21,379 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,379 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 192 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,379 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 204 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,379 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 352 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,379 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 352 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,379 DEBUG [RequestController-2] (RequestController.java:336) - rid: 352 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,379 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,380 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 352 opname: resolve starts with request processing 2013-06-17 14:09:21,380 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 352 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,380 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,380 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,380 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 192 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,380 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 192 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,380 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 352 opname: resolve ends with request processing 2013-06-17 14:09:21,381 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,381 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 196 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,381 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 208 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,381 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 354 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,381 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 354 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,382 DEBUG [RequestController-2] (RequestController.java:336) - rid: 354 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,382 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,382 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 354 opname: resolve starts with request processing 2013-06-17 14:09:21,382 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 354 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,382 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,382 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,382 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,382 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,383 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 354 opname: resolve ends with request processing 2013-06-17 14:09:21,383 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,384 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,384 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,384 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 356 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,384 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 356 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,384 DEBUG [RequestController-2] (RequestController.java:336) - rid: 356 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,384 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,384 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 356 opname: resolve starts with request processing 2013-06-17 14:09:21,384 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 356 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,385 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,385 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,385 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,385 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,385 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 356 opname: resolve ends with request processing 2013-06-17 14:09:21,386 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,386 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 232 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,386 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 244 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,386 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 358 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,386 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 358 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,386 DEBUG [RequestController-2] (RequestController.java:336) - rid: 358 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,387 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,387 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 358 opname: resolve starts with request processing 2013-06-17 14:09:21,387 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 358 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,387 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,432 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,432 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,437 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,437 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 358 opname: resolve ends with request processing 2013-06-17 14:09:21,486 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,487 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 208 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,487 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 220 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,487 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 360 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,487 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 360 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,488 DEBUG [RequestController-2] (RequestController.java:336) - rid: 360 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,490 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,490 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 360 opname: resolve starts with request processing 2013-06-17 14:09:21,490 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 360 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,491 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,491 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,491 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,491 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,491 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 360 opname: resolve ends with request processing 2013-06-17 14:09:21,492 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,492 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,492 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,492 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 362 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,493 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 362 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,493 DEBUG [RequestController-2] (RequestController.java:336) - rid: 362 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,493 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,493 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 362 opname: resolve starts with request processing 2013-06-17 14:09:21,493 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 362 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,493 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,493 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,493 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 204 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,493 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 204 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,493 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 362 opname: resolve ends with request processing 2013-06-17 14:09:21,494 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,494 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 196 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,494 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 208 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,495 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 364 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,495 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 364 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,495 DEBUG [RequestController-2] (RequestController.java:336) - rid: 364 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,495 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,495 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 364 opname: resolve starts with request processing 2013-06-17 14:09:21,495 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 364 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,495 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,495 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,496 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 196 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,496 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 196 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,496 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 364 opname: resolve ends with request processing 2013-06-17 14:09:21,497 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,497 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 188 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,497 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 200 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,497 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 366 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,497 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 366 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,498 DEBUG [RequestController-2] (RequestController.java:336) - rid: 366 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,498 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,498 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 366 opname: resolve starts with request processing 2013-06-17 14:09:21,498 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 366 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,498 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,498 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,498 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,498 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,498 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 366 opname: resolve ends with request processing 2013-06-17 14:09:21,499 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,499 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,500 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,500 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 368 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,500 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 368 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,500 DEBUG [RequestController-2] (RequestController.java:336) - rid: 368 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,500 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,500 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 368 opname: resolve starts with request processing 2013-06-17 14:09:21,500 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 368 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,507 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,507 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,508 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 208 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,508 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 208 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,508 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 368 opname: resolve ends with request processing 2013-06-17 14:09:21,515 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,515 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 200 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,516 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 212 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,516 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 370 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,516 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 370 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,516 DEBUG [RequestController-2] (RequestController.java:336) - rid: 370 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,516 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,516 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 370 opname: resolve starts with request processing 2013-06-17 14:09:21,516 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 370 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,516 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,516 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,517 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,517 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,517 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 370 opname: resolve ends with request processing 2013-06-17 14:09:21,518 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,518 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 184 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,518 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 196 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,518 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 372 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,518 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 372 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,518 DEBUG [RequestController-2] (RequestController.java:336) - rid: 372 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,518 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,518 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 372 opname: resolve starts with request processing 2013-06-17 14:09:21,519 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 372 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,519 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,519 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,519 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 192 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,519 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 192 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,519 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 372 opname: resolve ends with request processing 2013-06-17 14:09:21,520 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,520 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 232 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,520 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 244 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,520 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 374 opname: resolve _invoke: queuing request 2013-06-17 14:09:21,520 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 374 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:21,521 DEBUG [RequestController-2] (RequestController.java:336) - rid: 374 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:21,521 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:21,521 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 374 opname: resolve starts with request processing 2013-06-17 14:09:21,521 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 374 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:21,521 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:21,521 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:21,521 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 200 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:21,521 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 200 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:21,521 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 374 opname: resolve ends with request processing 2013-06-17 14:09:23,380 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:23,380 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:23,381 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:23,381 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 376 opname: resolve _invoke: queuing request 2013-06-17 14:09:23,381 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 376 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:23,381 DEBUG [RequestController-2] (RequestController.java:336) - rid: 376 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:23,381 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:23,381 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 376 opname: resolve starts with request processing 2013-06-17 14:09:23,381 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 376 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:23,382 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:23,382 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:23,382 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 140 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:23,382 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 140 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:23,382 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 376 opname: resolve ends with request processing 2013-06-17 14:09:28,387 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:28,387 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:28,388 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:28,388 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 378 opname: resolve _invoke: queuing request 2013-06-17 14:09:28,388 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 378 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:28,388 DEBUG [RequestController-2] (RequestController.java:336) - rid: 378 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:28,388 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:28,389 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 378 opname: resolve starts with request processing 2013-06-17 14:09:28,389 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 378 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:28,389 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:28,389 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:28,389 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 140 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:28,389 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 140 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:28,389 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 378 opname: resolve ends with request processing 2013-06-17 14:09:30,698 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:30,699 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:30,699 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:30,699 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 380 opname: resolve _invoke: queuing request 2013-06-17 14:09:30,699 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 380 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:30,699 DEBUG [RequestController-2] (RequestController.java:336) - rid: 380 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:30,699 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:30,699 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 380 opname: resolve starts with request processing 2013-06-17 14:09:30,700 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 380 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:30,700 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:30,700 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:30,700 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:30,700 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:30,700 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 380 opname: resolve ends with request processing 2013-06-17 14:09:30,707 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:30,707 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 224 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:30,707 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 236 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:30,708 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 382 opname: resolve _invoke: queuing request 2013-06-17 14:09:30,708 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 382 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:30,708 DEBUG [RequestController-2] (RequestController.java:336) - rid: 382 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:30,708 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:30,708 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 382 opname: resolve starts with request processing 2013-06-17 14:09:30,708 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 382 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:30,708 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:30,708 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:30,708 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 160 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:30,709 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 160 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:30,709 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 382 opname: resolve ends with request processing 2013-06-17 14:09:30,789 DEBUG [RequestProcessor-5] (ClientIIOPConnection.java:185) - Exception java.net.ConnectException: Connexion terminée par expiration du délai d'attente at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.jacorb.orb.factory.DefaultSocketFactory.doCreateSocket(DefaultSocketFactory.java:45) at org.jacorb.orb.factory.AbstractSocketFactory.createSocket(AbstractSocketFactory.java:60) at org.jacorb.orb.iiop.ClientIIOPConnection.createSocket(ClientIIOPConnection.java:314) at org.jacorb.orb.iiop.ClientIIOPConnection.connect(ClientIIOPConnection.java:149) at org.jacorb.orb.giop.GIOPConnection.sendMessage(GIOPConnection.java:1042) at org.jacorb.orb.giop.GIOPConnection.sendRequest(GIOPConnection.java:987) at org.jacorb.orb.giop.ClientConnection.sendRequest(ClientConnection.java:308) at org.jacorb.orb.giop.ClientConnection.sendRequest(ClientConnection.java:289) at org.jacorb.orb.Delegate._invoke_internal(Delegate.java:1335) at org.jacorb.orb.Delegate.invoke_internal(Delegate.java:1160) at org.jacorb.orb.Delegate.invoke(Delegate.java:1148) at org.jacorb.orb.Delegate.invokeBuiltin(Delegate.java:2039) at org.jacorb.orb.Delegate.non_existent(Delegate.java:1996) at org.omg.CORBA.portable.ObjectImpl._non_existent(ObjectImpl.java:61) at org.jacorb.naming.NamingContextImpl.isDead(NamingContextImpl.java:799) at org.jacorb.naming.NamingContextImpl.bind(NamingContextImpl.java:122) at org.omg.CosNaming.NamingContextExtPOA._invoke(NamingContextExtPOA.java:75) at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:348) at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:670) at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:820) 2013-06-17 14:09:30,790 INFO [RequestProcessor-5] (ClientIIOPConnection.java:194) - Retrying to connect to hampton.devci.net:50596 2013-06-17 14:09:31,341 DEBUG [RequestProcessor-5] (ClientIIOPConnection.java:303) - Trying to connect to hampton.devci.net:50596 with timeout=90000. 2013-06-17 14:09:33,413 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 12 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:33,413 DEBUG [ServerMessageReceptor0] (StreamConnectionBase.java:158) - read 204 bytes from kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:33,413 DEBUG [ServerMessageReceptor0] (GIOPConnection.java:492) - read GIOP message of size 216 from ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:33,413 DEBUG [ServerMessageReceptor0] (POA.java:507) - POA NameServer-POA rid: 384 opname: resolve _invoke: queuing request 2013-06-17 14:09:33,413 DEBUG [ServerMessageReceptor0] (RequestQueue.java:144) - rid: 384 opname: resolve is queued (queue size: 1) 2013-06-17 14:09:33,414 DEBUG [RequestController-2] (RequestController.java:336) - rid: 384 opname: resolve trying to get a RequestProcessor 2013-06-17 14:09:33,414 DEBUG [RequestController-2] (RequestController.java:580) - waiting for queue 2013-06-17 14:09:33,415 DEBUG [RequestProcessor-4] (RequestProcessor.java:808) - rid: 384 opname: resolve starts with request processing 2013-06-17 14:09:33,415 DEBUG [RequestProcessor-4] (RequestProcessor.java:316) - rid: 384 opname: resolve invokeOperation on servant (stream based) 2013-06-17 14:09:33,415 DEBUG [RequestProcessor-4] (ServerRequest.java:375) - ServerRequest: reply to resolve 2013-06-17 14:09:33,415 DEBUG [RequestProcessor-4] (GIOPConnection.java:1015) - GIOPConnection.sendMessage timeout (millis): 0 2013-06-17 14:09:33,415 DEBUG [RequestProcessor-4] (StreamConnectionBase.java:197) - wrote 140 bytes to kelowna.elt.fr.ds.corp:43051 2013-06-17 14:09:33,415 DEBUG [RequestProcessor-4] (GIOPConnection.java:1065) - wrote GIOP message of size 140 to ServerGIOPConnection to kelowna.elt.fr.ds.corp:43051 from [kelowna.elt.fr.ds.corp:14200] (305eac01) 2013-06-17 14:09:33,415 DEBUG [RequestProcessor-4] (RequestProcessor.java:827) - rid: 384 opname: resolve ends with request processing