cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Marco Matarazzo (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CASSANDRA-4426) CQL error on query prepare
Date Mon, 09 Jul 2012 20:15:36 GMT

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

Marco Matarazzo commented on CASSANDRA-4426:
--------------------------------------------

Paul: It's pretty high, I would say around 1 in 100, maybe more.

The strangest part that we noticed between yesterday and today is that it seems it happens
almost always when a new IP connect to the webserver and load the page. With "a new IP" I
mean an IP that the webserver hasn't seen for a while, let's say many hours. That makes no
sense to me: I'm sure the IP does not get pushed in any way through the webserver, and the
connection is always done by the webserver itself. Maybe is something related to the connection
getting reused... I'm completely lost here.

I am willing to collect any data I can, I just don't know what to look for.
                
> CQL error on query prepare
> --------------------------
>
>                 Key: CASSANDRA-4426
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-4426
>             Project: Cassandra
>          Issue Type: Bug
>    Affects Versions: 1.1.2
>            Reporter: Marco Matarazzo
>
> We're using (packaged) cassandra 1.1.2 on Ubuntu LTS 12.04 .
> This is a CF on a KS with replica_factor 3, on a cluster with 3 nodes:
> cqlsh:goh_release> DESCRIBE COLUMNFAMILY agents_skill 
> CREATE TABLE agents_skill (
>   agent_id ascii,
>   skill ascii,
>   value ascii,
>   PRIMARY KEY (agent_id, skill)
> ) WITH COMPACT STORAGE AND
>   comment='' AND
>   caching='KEYS_ONLY' AND
>   read_repair_chance=0.100000 AND
>   gc_grace_seconds=864000 AND
>   min_compaction_threshold=4 AND
>   max_compaction_threshold=32 AND
>   replicate_on_write='true' AND
>   compaction_strategy_class='SizeTieredCompactionStrategy' AND
>   compression_parameters:sstable_compression='SnappyCompressor';
> cqlsh:goh_release> 
> On this query : 
>    UPDATE agents_skill USING CONSISTENCY QUORUM SET value = ? WHERE agent_id = ? and
skill = ?
> ...sometimes we get this error on cql_prepare_query():
>    Error : line 1:78 mismatched input 'and' expecting EOF
> The error happens randomly (or with a pattern that I can't understand) and it does not
make any sense to me. Normally the query works, as I would expect.
> I am using PHPCassa, and I was not sure where the error could be. I somewhat remembered
that CQL should be passed to cassandra "as is", but not knowing Cassandra internal too well,
I took a very low-level approach... I hope is not too low :-)
> I see this on tcpdump when i receive the error:
> 18:49:51.800398 IP 10.0.3.177.42205 > 10.0.3.170.9160: Flags [P.], seq 840:979, ack
766, win 1047, options [nop,nop,TS val 130357758 ecr 135322260], length 139
>         0x0000:  aacc 0000 0208 aacc 0000 020f 0800 4500  ..............E.
>         0x0010:  00bf c2d9 4000 4006 5c05 0a00 03b1 0a00  ....@.@.\.......
>         0x0020:  03aa a4dd 23c8 16b9 de71 a9db 9466 8018  ....#....q...f..
>         0x0030:  0417 ad09 0000 0101 080a 07c5 19fe 0810  ................
>         0x0040:  da94 0000 0087 8001 0001 0000 0011 7072  ..............pr
>         0x0050:  6570 6172 655f 6371 6c5f 7175 6572 7900  epare_cql_query.
>         0x0060:  0000 000b 0001 0000 005b 5550 4441 5445  .........[UPDATE
>         0x0070:  2061 6765 6e74 735f 736b 696c 6c20 5553  .agents_skill.US
>         0x0080:  494e 4720 434f 4e53 4953 5445 4e43 5920  ING.CONSISTENCY.
>         0x0090:  5155 4f52 554d 2053 4554 2076 616c 7565  QUORUM.SET.value
>         0x00a0:  203d 203f 2057 4845 5245 2061 6765 6e74  .=.?.WHERE.agent
>         0x00b0:  5f69 6420 3d20 3f20 616e 6420 736b 696c  _id.=.?.and.skil
>         0x00c0:  6c20 3d20 3f08 0002 0000 0002 00         l.=.?........   
> 18:49:51.817323 IP 10.0.3.170.9160 > 10.0.3.177.42205: Flags [P.], seq 766:857, ack
979, win 587, options [nop,nop,TS val 135322264 ecr 130357758], length 91
>         0x0000:  aacc 0000 020f aacc 0000 0208 0800 4500  ..............E.
>         0x0010:  008f 4b1d 4000 4006 d3f1 0a00 03aa 0a00  ..K.@.@.........
>         0x0020:  03b1 23c8 a4dd a9db 9466 16b9 defc 8018  ..#......f......
>         0x0030:  024b 1bdc 0000 0101 080a 0810 da98 07c5  .K..............
>         0x0040:  19fe 0000 0057 8001 0002 0000 0011 7072  .....W........pr
>         0x0050:  6570 6172 655f 6371 6c5f 7175 6572 7900  epare_cql_query.
>         0x0060:  0000 000c 0001 0b00 0100 0000 2e6c 696e  .............lin
>         0x0070:  6520 313a 3738 206d 6973 6d61 7463 6865  e.1:78.mismatche
>         0x0080:  6420 696e 7075 7420 2761 6e64 2720 6578  d.input.'and'.ex
>         0x0090:  7065 6374 696e 6720 454f 4600 00         pecting.EOF..   
> Same query, some minutes later, worked (as I would expect) and I see this:
> 19:11:26.471750 IP 10.0.3.177.42283 > 10.0.3.170.9160: Flags [P.], seq 906:1045, ack
1181, win 1114, options [nop,nop,TS val 130681426 ecr 135645928], length 139
> 	0x0000:  aacc 0000 0208 aacc 0000 020f 0800 4500  ..............E.
> 	0x0010:  00bf 352a 4000 4006 e9b4 0a00 03b1 0a00  ..5*@.@.........
> 	0x0020:  03aa a52b 23c8 232a 42f7 c47b cf1e 8018  ...+#.#*B..{....
> 	0x0030:  045a 0578 0000 0101 080a 07ca 0a52 0815  .Z.x.........R..
> 	0x0040:  cae8 0000 0087 8001 0001 0000 0011 7072  ..............pr
> 	0x0050:  6570 6172 655f 6371 6c5f 7175 6572 7900  epare_cql_query.
> 	0x0060:  0000 000b 0001 0000 005b 5550 4441 5445  .........[UPDATE
> 	0x0070:  2061 6765 6e74 735f 736b 696c 6c20 5553  .agents_skill.US
> 	0x0080:  494e 4720 434f 4e53 4953 5445 4e43 5920  ING.CONSISTENCY.
> 	0x0090:  5155 4f52 554d 2053 4554 2076 616c 7565  QUORUM.SET.value
> 	0x00a0:  203d 203f 2057 4845 5245 2061 6765 6e74  .=.?.WHERE.agent
> 	0x00b0:  5f69 6420 3d20 3f20 616e 6420 736b 696c  _id.=.?.and.skil
> 	0x00c0:  6c20 3d20 3f08 0002 0000 0002 00         l.=.?........
> 19:11:26.472067 IP 10.0.3.170.9160 > 10.0.3.177.42283: Flags [P.], seq 1181:1318,
ack 1045, win 587, options [nop,nop,TS val 135645928 ecr 130681426], length 137
> 	0x0000:  aacc 0000 020f aacc 0000 0208 0800 4500  ..............E.
> 	0x0010:  00bd 0069 4000 4006 1e78 0a00 03aa 0a00  ...i@.@..x......
> 	0x0020:  03b1 23c8 a52b c47b cf1e 232a 4382 8018  ..#..+.{..#*C...
> 	0x0030:  024b 1c0a 0000 0101 080a 0815 cae8 07ca  .K..............
> 	0x0040:  0a52 0000 0085 8001 0002 0000 0011 7072  .R............pr
> 	0x0050:  6570 6172 655f 6371 6c5f 7175 6572 7900  epare_cql_query.
> 	0x0060:  0000 000c 0000 0800 0188 659f 9308 0002  ..........e.....
> 	0x0070:  0000 0003 0f00 030b 0000 0003 0000 0009  ................
> 	0x0080:  4173 6369 6954 7970 6500 0000 0941 7363  AsciiType....Asc
> 	0x0090:  6969 5479 7065 0000 0009 4173 6369 6954  iiType....AsciiT
> 	0x00a0:  7970 650f 0004 0b00 0000 0300 0000 0576  ype............v
> 	0x00b0:  616c 7565 0000 0008 6167 656e 745f 6964  alue....agent_id
> 	0x00c0:  0000 0005 736b 696c 6c00 00              ....skill..
> When i get the error I just see this on system.log :
> DEBUG [Thrift:1637] 2012-07-07 18:49:51,800 CassandraServer.java (line 1250) prepare_cql_query
> DEBUG [Thrift:1637] 2012-07-07 18:49:51,818 CustomTThreadPoolServer.java (line 196) Thrift
transport error occurred during processing of message.
> org.apache.thrift.transport.TTransportException
>         at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132)
>         at org.apache.thrift.transport.TTransport.readAll(TTransport.java:84)
>         at org.apache.thrift.transport.TFramedTransport.readFrame(TFramedTransport.java:129)
>         at org.apache.thrift.transport.TFramedTransport.read(TFramedTransport.java:101)
>         at org.apache.thrift.transport.TTransport.readAll(TTransport.java:84)
>         at org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:378)
>         at org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:297)
>         at org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:204)
>         at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:22)
>         at org.apache.cassandra.thrift.CustomTThreadPoolServer$WorkerProcess.run(CustomTThreadPoolServer.java:186)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
>         at java.lang.Thread.run(Unknown Source)
> Enabling TRACE does not give much more, to my eyes:
> DEBUG [Thrift:11] 2012-07-07 19:34:51,284 CassandraServer.java (line 1250) prepare_cql_query
> TRACE [Thrift:11] 2012-07-07 19:34:51,284 QueryProcessor.java (line 883) CQL QUERY: UPDATE
agents_skill USING CONSISTENCY QUORUM SET value = ? WHERE agent_id = ? and skill = ?
> DEBUG [ReadRepairStage:2] 2012-07-07 19:34:51,285 RowDigestResolver.java (line 110) resolve:
2 ms.
> DEBUG [Thrift:11] 2012-07-07 19:34:51,286 CustomTThreadPoolServer.java (line 196) Thrift
transport error occurred during processing of message.
> org.apache.thrift.transport.TTransportException
>         at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132)
>         at org.apache.thrift.transport.TTransport.readAll(TTransport.java:84)
>         at org.apache.thrift.transport.TFramedTransport.readFrame(TFramedTransport.java:129)
>         at org.apache.thrift.transport.TFramedTransport.read(TFramedTransport.java:101)
>         at org.apache.thrift.transport.TTransport.readAll(TTransport.java:84)
>         at org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:378)
>         at org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:297)
>         at org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:204)
>         at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:22)
>         at org.apache.cassandra.thrift.CustomTThreadPoolServer$WorkerProcess.run(CustomTThreadPoolServer.java:186)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
>         at java.lang.Thread.run(Unknown Source)
> DEBUG [Thrift:11] 2012-07-07 19:34:51,294 ClientState.java (line 130) logged out: #<User
allow_all groups=[]>

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Mime
View raw message