You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@drill.apache.org by "Rob Wu (JIRA)" <ji...@apache.org> on 2017/07/19 00:45:00 UTC

[jira] [Comment Edited] (DRILL-5659) C++ Client (master) behavior is unstable resulting incorrect result or exception in API calls

    [ https://issues.apache.org/jira/browse/DRILL-5659?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16092412#comment-16092412 ] 

Rob Wu edited comment on DRILL-5659 at 7/19/17 12:44 AM:
---------------------------------------------------------

Tested Linux 1.11 master snapshot against 1.9.0 and 1.10.0 drillbits with authentication.
Just compiled windows and tested against 1.9.0 worked correctly. 
[~laurentgo] [~parthc] Have you tried with windows? I seemed to be getting error testing against 1.10+ drillbits when receiving server metadata in processServerMetaResult(...) resulting socket shutdown.


{code:java}
Drill Client Library
Build info:
Loaded by process: C:\Program Files (x86)\Microsoft Data Access SDK 2.8\Tools\amd64\odbct32w.exe
Current process id is: 9300
Initialized Logging to file (D:\Logs\DM\drillclient20170718T173700.log). 
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Connecting to endpoint: 192.168.205.161:31010
2017-Jul-18 17:37:00 : TRACE   : 2d48 : 192.168.205.161:31010
2017-Jul-18 17:37:00 : INFO    : 2d48 : Connected to endpoint: id: 396 address: 192.168.205.161:31010
2017-Jul-18 17:37:00 : TRACE   : 2d48 : validateHandShake
2017-Jul-18 17:37:00 : INFO    : 2d48 : userName:mapr
2017-Jul-18 17:37:00 : INFO    : 2d48 : password: ********** 
2017-Jul-18 17:37:00 : INFO    : 2d48 : schema:default
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Sent handshake request message. Coordination id: 1221
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Started new handshake wait timer with 5 seconds.
2017-Jul-18 17:37:00 : DEBUG   : 2d48 : DrillClientImpl::recvHandshake: async read waiting for server handshake response.
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Deadline timer cancelled.
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Socket read: reading 87data bytes
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Socket read: actual bytes read = 87
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Started new heartbeat timer with 15 seconds.
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : DrillClientImpl::startMessageListener: io_service is stopped. Restarting.
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : DrillClientImpl::startMessageListener: Starting listener thread: 0000000003E61200
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Getting metadata
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Server metadata supported.
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : Sent GET_SERVER_META request. [id: 396 address: 192.168.205.161:31010]Coordination id = 1222
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : Sent GET_SERVER_META Coordination id = 1222 query: server meta
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : Sending GET_SERVER_META request. Number of pending requests = 1
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Read blocked waiting for memory.
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Started new query wait timer with 180 seconds.
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Started new heartbeat timer with 15 seconds.
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl:: Heartbeat timer expired.
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl::handleRead: Handle Read from buffer 0000000003E615C0
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl::handleRead: Cancel deadline timer.
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : DrillClientImpl::getNextResult: async_read from the server
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Server metadata received.
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Getting new message
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl::readMsg: Read message from buffer 0000000003E615C0
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Length bytes = 2
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Msg Length = 5637
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl::readLenBytesFromSocket: Allocated and locked buffer: [ 0000000003E11CB0, size = 5639 ]
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Copied bufWithLen into bufferWithLenBytes. Now reading data (rmsgLen - leftover) : 5634
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Socket read: reading 5634data bytes
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Getting metadata
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Server metadata supported.
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Socket read: actual bytes read = 5634
2017-Jul-18 17:37:06 : TRACE   : 3fc4 : Successfully created a RPC message with Coordination id: 1222
2017-Jul-18 17:37:06 : TRACE   : 3fc4 : DrillClientImpl::readMsg: Free buffer 0000000003E615C0
2017-Jul-18 17:37:10 : DEBUG   : 3fc4 : Processing GetServerMetaResp with coordination id:1222
2017-Jul-18 17:37:29 : TRACE   : 3fc4 : Socket shutdown
2017-Jul-18 17:37:30 : TRACE   : 3fc4 : DrillClientImpl:: Heartbeat timer expired.
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Socket shutdown
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Server metadata received.
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Getting metadata
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Server metadata supported.
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Socket shutdown
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Server metadata received.
{code}



was (Author: robertw):
Tested Linux 1.11 master snapshot against 1.9.0 and 1.10.0 drillbits with authentication.
Just compiled windows and tested against 1.9.0 worked correctly. 
[~laurentgo] [~parthc] Have you tried with windows? I seemed to be getting error when receiving server metadata in processServerMetaResult(...) resulting socket shutdown.


{code:java}
Drill Client Library
Build info:
Loaded by process: C:\Program Files (x86)\Microsoft Data Access SDK 2.8\Tools\amd64\odbct32w.exe
Current process id is: 9300
Initialized Logging to file (D:\Logs\DM\drillclient20170718T173700.log). 
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Connecting to endpoint: 192.168.205.161:31010
2017-Jul-18 17:37:00 : TRACE   : 2d48 : 192.168.205.161:31010
2017-Jul-18 17:37:00 : INFO    : 2d48 : Connected to endpoint: id: 396 address: 192.168.205.161:31010
2017-Jul-18 17:37:00 : TRACE   : 2d48 : validateHandShake
2017-Jul-18 17:37:00 : INFO    : 2d48 : userName:mapr
2017-Jul-18 17:37:00 : INFO    : 2d48 : password: ********** 
2017-Jul-18 17:37:00 : INFO    : 2d48 : schema:default
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Sent handshake request message. Coordination id: 1221
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Started new handshake wait timer with 5 seconds.
2017-Jul-18 17:37:00 : DEBUG   : 2d48 : DrillClientImpl::recvHandshake: async read waiting for server handshake response.
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Deadline timer cancelled.
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Socket read: reading 87data bytes
2017-Jul-18 17:37:00 : TRACE   : 2d48 : Socket read: actual bytes read = 87
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Started new heartbeat timer with 15 seconds.
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : DrillClientImpl::startMessageListener: io_service is stopped. Restarting.
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : DrillClientImpl::startMessageListener: Starting listener thread: 0000000003E61200
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Getting metadata
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Server metadata supported.
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : Sent GET_SERVER_META request. [id: 396 address: 192.168.205.161:31010]Coordination id = 1222
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : Sent GET_SERVER_META Coordination id = 1222 query: server meta
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : Sending GET_SERVER_META request. Number of pending requests = 1
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Read blocked waiting for memory.
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Started new query wait timer with 180 seconds.
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Started new heartbeat timer with 15 seconds.
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl:: Heartbeat timer expired.
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl::handleRead: Handle Read from buffer 0000000003E615C0
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl::handleRead: Cancel deadline timer.
2017-Jul-18 17:37:03 : DEBUG   : 2d48 : DrillClientImpl::getNextResult: async_read from the server
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Server metadata received.
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Getting new message
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl::readMsg: Read message from buffer 0000000003E615C0
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Length bytes = 2
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Msg Length = 5637
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : DrillClientImpl::readLenBytesFromSocket: Allocated and locked buffer: [ 0000000003E11CB0, size = 5639 ]
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Copied bufWithLen into bufferWithLenBytes. Now reading data (rmsgLen - leftover) : 5634
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Socket read: reading 5634data bytes
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Getting metadata
2017-Jul-18 17:37:03 : TRACE   : 2d48 : Server metadata supported.
2017-Jul-18 17:37:03 : TRACE   : 3fc4 : Socket read: actual bytes read = 5634
2017-Jul-18 17:37:06 : TRACE   : 3fc4 : Successfully created a RPC message with Coordination id: 1222
2017-Jul-18 17:37:06 : TRACE   : 3fc4 : DrillClientImpl::readMsg: Free buffer 0000000003E615C0
2017-Jul-18 17:37:10 : DEBUG   : 3fc4 : Processing GetServerMetaResp with coordination id:1222
2017-Jul-18 17:37:29 : TRACE   : 3fc4 : Socket shutdown
2017-Jul-18 17:37:30 : TRACE   : 3fc4 : DrillClientImpl:: Heartbeat timer expired.
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Socket shutdown
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Server metadata received.
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Getting metadata
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Server metadata supported.
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Socket shutdown
2017-Jul-18 17:37:30 : TRACE   : 2d48 : Server metadata received.
{code}


> C++ Client (master) behavior is unstable resulting incorrect result or exception in API calls
> ---------------------------------------------------------------------------------------------
>
>                 Key: DRILL-5659
>                 URL: https://issues.apache.org/jira/browse/DRILL-5659
>             Project: Apache Drill
>          Issue Type: Bug
>    Affects Versions: 1.11.0
>            Reporter: Rob Wu
>            Assignee: Parth Chandra
>              Labels: ready-to-commit
>             Fix For: 1.11.0
>
>         Attachments: 1-10cppClient-1.10.0Drillbit-hive.log, 1-10cppClient-1.10.0Drillbit-metadata and catalog test.log, 1-10cppClient-1.9.0Drillbit-dfs.log, 1-10cppClient-1.9.0Drillbit-hive.log, 1-10cppClient-1.9.0Drillbit-metadata and catalog test.log, 1-11cppClient-1.10.0Drillbit-hive.log, 1-11cppClient-1.10.0Drillbit-metadata and catalog test.log, 1-11cppClient-1.9.0Drillbit-dfs.log, 1-11cppClient-1.9.0Drillbit-hive.log, 1-11cppClient-1.9.0Drillbit-metadata and catalog test.log
>
>
> I recently compiled the C++ client (on windows) from master and tested against a 1.9.0 drillbit. The client's behavior does not meet the stable release requirement.
> Some API functionalities are broken and should be investigated.
> Most noticeable is the getColumns(...) call. It will throw an exception with "Cannot decode getcolumns results" when the number of rows (column records) exceeds a certain number. 
> I also noticed that: during query execution + data retrieval, if the table is large enough, the result coming back will start to become NULL or empty.
> I will see if I can generate some drillclient logs to put in the attachment.
> I will also compile and test on other platforms.



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)