Vertica Pulse got socket closed abnormally

John_Ho

Hi Vertica Pulse Team,

I'm trying Vertica Pulse 7.1.1 on CentOS 6.6 x86_64 running with Vertica 7.1.1-0 and it gets socket closed abnormally exception:

2014-12-10 15:09:59.444 [Java-23379] 0x14 com.vertica.sdk.UdfException: Socket Socket[addr=/127.0.0.1,port=49898,localport=47523] has been closed abnormally
        at com.vertica.udxfence.UDxRPCMessage.recvall(UDxRPCMessage.java:111)
        at com.vertica.udxfence.UDxRPCMessage.recv(UDxRPCMessage.java:88)
        at com.vertica.udxfence.UDxExecContext.run(UDxExecContext.java:168)
        at java.lang.Thread.run(Thread.java:745)

Are there any parameters that we should change to solve the problem?

Thanks,
John

Prasanta_Pal

select set_debug_log('EE','UDX_FENCE');

Check the details in UDxLogs if you can find the cause of the failure.

and then clear

select clear_debug_log('ee','udx_fence');

PRana

HI John,

This is a normal message that we see when vertica closes the socket to the java side process. Does you query error out?

Pratibha

John_Ho

Hi Prasanta, Pratibha,

Many thanks for your support.
This is the query error:

ERROR 3399:  Failure in UDx RPC call InvokeProcessPartition(): Error in User Defined Object [SentimentAnalysis], error code: 0
String index out of range: -1

I turned on the debug log and got additional log before socket closed:

2014-12-18 11:34:21.255 [Java-2224] 0x1f [DEBUG] processPartitionForUDT for 'SentimentAnalysis' (com.vertica.SentimentUDx.SentimentAnalysisDefaultFactory) in [/home/dbadmin/big/v_big_node0002_catalog/Libraries/public_SentimentLib_45035996273738278/public_SentimentLib_45035996273738278.jar]
2014-12-18 11:34:21.255 [Java-2224] 0x1f [DEBUG] calling processPartitionForUDT()
2014-12-18 11:34:21.257 [Java-2224] 0x1e [DEBUG] returned from processPartitionForUDT()
2014-12-18 11:34:21.267 [Java-2224] 0x01 [DEBUG] Created thread 0x21 on socket=Socket[addr=/127.0.0.1,port=53500,localport=57673]
2014-12-18 11:34:21.267 [Java-2224] 0x21 [DEBUG] UDxExecContext()::run()
2014-12-18 11:34:21.269 [Java-2224] 0x21 [DEBUG] cancel for 'name not yet bound' () in []
2014-12-18 11:34:21.269 [Java-2224] 0x21 [DEBUG] calling cancel()
2014-12-18 11:34:21.270 [Java-2224] 0x21 [DEBUG] returned from cancel()
2014-12-18 11:34:21.271 [Java-2224] 0x01 [DEBUG] Created thread 0x22 on socket=Socket[addr=/127.0.0.1,port=53501,localport=57673]
2014-12-18 11:34:21.272 [Java-2224] 0x22 [DEBUG] UDxExecContext()::run()
2014-12-18 11:34:21.272 [Java-2224] 0x22 [DEBUG] cancel for 'name not yet bound' () in []
2014-12-18 11:34:21.272 [Java-2224] 0x22 [DEBUG] calling cancel()
2014-12-18 11:34:21.272 [Java-2224] 0x22 [DEBUG] returned from cancel()
2014-12-18 11:34:21.273 [Java-2224] 0x22 [DEBUG] Terminating thread id = 0x22
2014-12-18 11:34:21.273 [Java-2224] 0x23 [DEBUG] UDxExecContext()::run()
2014-12-18 11:34:21.273 [Java-2224] 0x21 [DEBUG] Terminating thread id = 0x21
2014-12-18 11:34:21.273 [Java-2224] 0x01 [DEBUG] Created thread 0x23 on socket=Socket[addr=/127.0.0.1,port=53502,localport=57673]
2014-12-18 11:34:21.273 [Java-2224] 0x23 [DEBUG] cancel for 'name not yet bound' () in []
2014-12-18 11:34:21.275 [Java-2224] 0x23 [DEBUG] calling cancel()
2014-12-18 11:34:21.275 [Java-2224] 0x23 [DEBUG] returned from cancel()
2014-12-18 11:34:21.275 [Java-2224] 0x23 [DEBUG] Terminating thread id = 0x23
2014-12-18 11:34:21.276 [Java-2224] 0x01 [DEBUG] Created thread 0x24 on socket=Socket[addr=/127.0.0.1,port=53503,localport=57673]
2014-12-18 11:34:21.276 [Java-2224] 0x24 [DEBUG] UDxExecContext()::run()
2014-12-18 11:34:21.276 [Java-2224] 0x24 [DEBUG] cancel for 'name not yet bound' () in []
2014-12-18 11:34:21.276 [Java-2224] 0x24 [DEBUG] calling cancel()
2014-12-18 11:34:21.276 [Java-2224] 0x24 [DEBUG] returned from cancel()
2014-12-18 11:34:21.277 [Java-2224] 0x24 [DEBUG] Terminating thread id = 0x24
...
2014-12-18 11:34:21.300 [Java-2224] 0x18 [DEBUG] returned from processPartitionForUDT()
2014-12-18 11:34:21.307 [Java-2224] 0x15 [DEBUG] destroy for 'SentimentAnalysis' (com.vertica.SentimentUDx.SentimentAnalysisDefaultFactory) in [/home/dbadmin/big/v_big_node0002_catalog/Libraries/public_SentimentLib_45035996273738278/public_SentimentLib_45035996273738278.jar]
2014-12-18 11:34:21.307 [Java-2224] 0x15 [DEBUG] calling destroy()
2014-12-18 11:34:21.307 [Java-2224] 0x15 [DEBUG] returned from destroy()
2014-12-18 11:34:21.309 [Java-2224] 0x15 com.vertica.sdk.UdfException: Socket Socket[addr=/127.0.0.1,port=53285,localport=57673] has been closed abnormally
        at com.vertica.udxfence.UDxRPCMessage.recvall(UDxRPCMessage.java:111)
        at com.vertica.udxfence.UDxRPCMessage.recv(UDxRPCMessage.java:88)
        at com.vertica.udxfence.UDxExecContext.run(UDxExecContext.java:168)
        at java.lang.Thread.run(Thread.java:745)

PRana

Hi John,

Can I get a look at your query and the UDx code. I'll be able to debug it better if I have a reproducer. The query error suggests a bug in the Udx code.

Pratibha

John_Ho

Hi Pratibha,

Have you got any update from Vertica Pulse team regarding the UDx code?
Thanks,

John