[
https://issues.apache.org/jira/browse/CASSANDRA-11465?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15375145#comment-15375145
]
Jim Witschey commented on CASSANDRA-11465:
------------------------------------------
Another failure we're seeing:
http://cassci.datastax.com/job/trunk_dtest/1288/testReport/junit/cql_tracing_test/TestCqlTracing/tracing_unknown_impl_test/
{code}
'/127.0.0.1' not found in "Consistency level set to ALL.\nNow Tracing is
enabled\n\nTracing session: 54778be0-3c80-11e6-a333-ef4c703100c3\n\n activity
|
timestamp | source | source_elapsed |
client\n----------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------\n
Execute CQL3
query | 2016-06-27 16:00:55.198000 | 127.0.0.1 | 0 | 127.0.0.1\n
Parsing INSERT INTO ks.users (userid, firstname, lastname, age) VALUES
(550e8400-e29b-41d4-a716-446655440000, 'Frodo', 'Baggins', 32);
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.198000 | 127.0.0.1 |
462 | 127.0.0.1\n
Preparing statement
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.199000 | 127.0.0.1 |
953 | 127.0.0.1\n
Determining replicas for mutation
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.200000 | 127.0.0.1 |
1773 | 127.0.0.1\n
Sending MUTATION message to /127.0.0.3
[MessagingService-Outgoing-/127.0.0.3] | 2016-06-27 16:00:55.202000 | 127.0.0.1
| 4094 | 127.0.0.1\n
Sending MUTATION message to /127.0.0.2
[MessagingService-Outgoing-/127.0.0.2] | 2016-06-27 16:00:55.202000 | 127.0.0.1
| 4117 | 127.0.0.1\n
Appending to
commitlog [Native-Transport-Requests-2] | 2016-06-27 16:00:55.202000 |
127.0.0.1 | 4270 | 127.0.0.1\n
Adding
to users memtable [Native-Transport-Requests-2] | 2016-06-27 16:00:55.203000 |
127.0.0.1 | 4758 | 127.0.0.1\n
REQUEST_RESPONSE message received from
/127.0.0.3 [MessagingService-Incoming-/127.0.0.3] | 2016-06-27 16:00:55.213000
| 127.0.0.1 | 14833 | 127.0.0.1\n
Processing
response from /127.0.0.3 [RequestResponseStage-4] | 2016-06-27 16:00:55.213000
| 127.0.0.1 | 15059 | 127.0.0.1\n
REQUEST_RESPONSE message received from
/127.0.0.2 [MessagingService-Incoming-/127.0.0.2] | 2016-06-27 16:00:55.217000
| 127.0.0.1 | 19203 | 127.0.0.1\n
Processing
response from /127.0.0.2 [RequestResponseStage-1] | 2016-06-27 16:00:55.217000
| 127.0.0.1 | 19379 | 127.0.0.1\n
Request complete | 2016-06-27 16:00:55.217557 |
127.0.0.1 | 19557 | 127.0.0.1\n\n\n"
-------------------- >> begin captured logging << --------------------
dtest: DEBUG: cluster ccm directory: /tmp/dtest-RJbUwP
dtest: DEBUG: Custom init_config not found. Setting defaults.
dtest: DEBUG: Done setting configuration options:
{ 'initial_token': None,
'num_tokens': '32',
'phi_convict_threshold': 5,
'range_request_timeout_in_ms': 10000,
'read_request_timeout_in_ms': 10000,
'request_timeout_in_ms': 10000,
'truncate_request_timeout_in_ms': 10000,
'write_request_timeout_in_ms': 10000}
dtest: DEBUG: Consistency level set to ALL.
Now Tracing is enabled
Tracing session: 54778be0-3c80-11e6-a333-ef4c703100c3
activity
| timestamp | source | source_elapsed | client
----------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------
Execute CQL3
query | 2016-06-27 16:00:55.198000 | 127.0.0.1 | 0 | 127.0.0.1
Parsing INSERT INTO ks.users (userid, firstname, lastname, age) VALUES
(550e8400-e29b-41d4-a716-446655440000, 'Frodo', 'Baggins', 32);
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.198000 | 127.0.0.1 |
462 | 127.0.0.1
Preparing statement
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.199000 | 127.0.0.1 |
953 | 127.0.0.1
Determining replicas for mutation
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.200000 | 127.0.0.1 |
1773 | 127.0.0.1
Sending MUTATION message to /127.0.0.3
[MessagingService-Outgoing-/127.0.0.3] | 2016-06-27 16:00:55.202000 | 127.0.0.1
| 4094 | 127.0.0.1
Sending MUTATION message to /127.0.0.2
[MessagingService-Outgoing-/127.0.0.2] | 2016-06-27 16:00:55.202000 | 127.0.0.1
| 4117 | 127.0.0.1
Appending to commitlog
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.202000 | 127.0.0.1 |
4270 | 127.0.0.1
Adding to users memtable
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.203000 | 127.0.0.1 |
4758 | 127.0.0.1
REQUEST_RESPONSE message received from /127.0.0.3
[MessagingService-Incoming-/127.0.0.3] | 2016-06-27 16:00:55.213000 | 127.0.0.1
| 14833 | 127.0.0.1
Processing response from /127.0.0.3
[RequestResponseStage-4] | 2016-06-27 16:00:55.213000 | 127.0.0.1 |
15059 | 127.0.0.1
REQUEST_RESPONSE message received from /127.0.0.2
[MessagingService-Incoming-/127.0.0.2] | 2016-06-27 16:00:55.217000 | 127.0.0.1
| 19203 | 127.0.0.1
Processing response from /127.0.0.2
[RequestResponseStage-1] | 2016-06-27 16:00:55.217000 | 127.0.0.1 |
19379 | 127.0.0.1
Request
complete | 2016-06-27 16:00:55.217557 | 127.0.0.1 | 19557 | 127.0.0.1
--------------------- >> end captured logging << ---------------------
Stacktrace
File "/usr/lib/python2.7/unittest/case.py", line 329, in run
testMethod()
File "/home/automaton/cassandra-dtest/tools.py", line 288, in wrapped
f(obj)
File "/home/automaton/cassandra-dtest/cql_tracing_test.py", line 126, in
tracing_unknown_impl_test
self.trace(session)
File "/home/automaton/cassandra-dtest/cql_tracing_test.py", line 75, in trace
self.assertIn('/127.0.0.1', out)
File "/usr/lib/python2.7/unittest/case.py", line 803, in assertIn
self.fail(self._formatMessage(msg, standardMsg))
File "/usr/lib/python2.7/unittest/case.py", line 410, in fail
raise self.failureException(msg)
'\'/127.0.0.1\' not found in "Consistency level set to ALL.\\nNow Tracing is
enabled\\n\\nTracing session: 54778be0-3c80-11e6-a333-ef4c703100c3\\n\\n
activity
| timestamp | source | source_elapsed |
client\\n----------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------\\n
Execute CQL3
query | 2016-06-27 16:00:55.198000 | 127.0.0.1 | 0 | 127.0.0.1\\n
Parsing INSERT INTO ks.users (userid, firstname, lastname, age) VALUES
(550e8400-e29b-41d4-a716-446655440000, \'Frodo\', \'Baggins\', 32);
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.198000 | 127.0.0.1 |
462 | 127.0.0.1\\n
Preparing statement
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.199000 | 127.0.0.1 |
953 | 127.0.0.1\\n
Determining replicas for mutation
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.200000 | 127.0.0.1 |
1773 | 127.0.0.1\\n
Sending MUTATION message to /127.0.0.3
[MessagingService-Outgoing-/127.0.0.3] | 2016-06-27 16:00:55.202000 | 127.0.0.1
| 4094 | 127.0.0.1\\n
Sending MUTATION message to /127.0.0.2
[MessagingService-Outgoing-/127.0.0.2] | 2016-06-27 16:00:55.202000 | 127.0.0.1
| 4117 | 127.0.0.1\\n
Appending to
commitlog [Native-Transport-Requests-2] | 2016-06-27 16:00:55.202000 |
127.0.0.1 | 4270 | 127.0.0.1\\n
Adding
to users memtable [Native-Transport-Requests-2] | 2016-06-27 16:00:55.203000 |
127.0.0.1 | 4758 | 127.0.0.1\\n
REQUEST_RESPONSE message received from
/127.0.0.3 [MessagingService-Incoming-/127.0.0.3] | 2016-06-27 16:00:55.213000
| 127.0.0.1 | 14833 | 127.0.0.1\\n
Processing
response from /127.0.0.3 [RequestResponseStage-4] | 2016-06-27 16:00:55.213000
| 127.0.0.1 | 15059 | 127.0.0.1\\n
REQUEST_RESPONSE message received from
/127.0.0.2 [MessagingService-Incoming-/127.0.0.2] | 2016-06-27 16:00:55.217000
| 127.0.0.1 | 19203 | 127.0.0.1\\n
Processing
response from /127.0.0.2 [RequestResponseStage-1] | 2016-06-27 16:00:55.217000
| 127.0.0.1 | 19379 | 127.0.0.1\\n
Request complete | 2016-06-27 16:00:55.217557 |
127.0.0.1 | 19557 | 127.0.0.1\\n\\n\\n"\n-------------------- >> begin
captured logging << --------------------\ndtest: DEBUG: cluster ccm directory:
/tmp/dtest-RJbUwP\ndtest: DEBUG: Custom init_config not found. Setting
defaults.\ndtest: DEBUG: Done setting configuration options:\n{
\'initial_token\': None,\n \'num_tokens\': \'32\',\n
\'phi_convict_threshold\': 5,\n \'range_request_timeout_in_ms\': 10000,\n
\'read_request_timeout_in_ms\': 10000,\n \'request_timeout_in_ms\': 10000,\n
\'truncate_request_timeout_in_ms\': 10000,\n
\'write_request_timeout_in_ms\': 10000}\ndtest: DEBUG: Consistency level set to
ALL.\nNow Tracing is enabled\n\nTracing session:
54778be0-3c80-11e6-a333-ef4c703100c3\n\n activity
| timestamp |
source | source_elapsed |
client\n----------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------\n
Execute CQL3
query | 2016-06-27 16:00:55.198000 | 127.0.0.1 | 0 | 127.0.0.1\n
Parsing INSERT INTO ks.users (userid, firstname, lastname, age) VALUES
(550e8400-e29b-41d4-a716-446655440000, \'Frodo\', \'Baggins\', 32);
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.198000 | 127.0.0.1 |
462 | 127.0.0.1\n
Preparing statement
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.199000 | 127.0.0.1 |
953 | 127.0.0.1\n
Determining replicas for mutation
[Native-Transport-Requests-2] | 2016-06-27 16:00:55.200000 | 127.0.0.1 |
1773 | 127.0.0.1\n
Sending MUTATION message to /127.0.0.3
[MessagingService-Outgoing-/127.0.0.3] | 2016-06-27 16:00:55.202000 | 127.0.0.1
| 4094 | 127.0.0.1\n
Sending MUTATION message to /127.0.0.2
[MessagingService-Outgoing-/127.0.0.2] | 2016-06-27 16:00:55.202000 | 127.0.0.1
| 4117 | 127.0.0.1\n
Appending to
commitlog [Native-Transport-Requests-2] | 2016-06-27 16:00:55.202000 |
127.0.0.1 | 4270 | 127.0.0.1\n
Adding
to users memtable [Native-Transport-Requests-2] | 2016-06-27 16:00:55.203000 |
127.0.0.1 | 4758 | 127.0.0.1\n
REQUEST_RESPONSE message received from
/127.0.0.3 [MessagingService-Incoming-/127.0.0.3] | 2016-06-27 16:00:55.213000
| 127.0.0.1 | 14833 | 127.0.0.1\n
Processing
response from /127.0.0.3 [RequestResponseStage-4] | 2016-06-27 16:00:55.213000
| 127.0.0.1 | 15059 | 127.0.0.1\n
REQUEST_RESPONSE message received from
/127.0.0.2 [MessagingService-Incoming-/127.0.0.2] | 2016-06-27 16:00:55.217000
| 127.0.0.1 | 19203 | 127.0.0.1\n
Processing
response from /127.0.0.2 [RequestResponseStage-1] | 2016-06-27 16:00:55.217000
| 127.0.0.1 | 19379 | 127.0.0.1\n
Request complete | 2016-06-27 16:00:55.217557 |
127.0.0.1 | 19557 | 127.0.0.1\n\n\n\n--------------------- >> end
captured logging << ---------------------'
Standard Output
(EE) (EE) (EE)
{code}
We should be seeing all those trace entries. Here's an example of the output
from a successful trace in a successful local run:
{code}
activity
| timestamp | source | source_elapsed | client
----------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------+-----------
Execute CQL3
query | 2016-07-13 10:47:36.596000 | 127.0.0.1 | 0 | 127.0.0.1
Parsing INSERT INTO ks.users (userid, firstname, lastname, age) VALUES
(550e8400-e29b-41d4-a716-446655440000, 'Frodo', 'Baggins', 32);
[Native-Transport-Requests-2] | 2016-07-13 10:47:36.596000 | 127.0.0.1 |
240 | 127.0.0.1
Preparing statement
[Native-Transport-Requests-2] | 2016-07-13 10:47:36.596000 | 127.0.0.1 |
502 | 127.0.0.1
Determining replicas for mutation
[Native-Transport-Requests-2] | 2016-07-13 10:47:36.597000 | 127.0.0.1 |
997 | 127.0.0.1
Sending MUTATION message to /127.0.0.2
[MessagingService-Outgoing-/127.0.0.2] | 2016-07-13 10:47:36.597000 | 127.0.0.1
| 1557 | 127.0.0.1
Sending MUTATION message to /127.0.0.3
[MessagingService-Outgoing-/127.0.0.3] | 2016-07-13 10:47:36.598000 | 127.0.0.1
| 2138 | 127.0.0.1
MUTATION message received from /127.0.0.1
[MessagingService-Incoming-/127.0.0.1] | 2016-07-13 10:47:36.599000 | 127.0.0.2
| 457 | 127.0.0.1
MUTATION message received from /127.0.0.1
[MessagingService-Incoming-/127.0.0.1] | 2016-07-13 10:47:36.600000 | 127.0.0.3
| 347 | 127.0.0.1
Appending to commitlog
[MutationStage-1] | 2016-07-13 10:47:36.600000 | 127.0.0.1 | 3996 |
127.0.0.1
Adding to users memtable
[MutationStage-1] | 2016-07-13 10:47:36.600000 | 127.0.0.1 | 4332 |
127.0.0.1
Appending to commitlog
[MutationStage-2] | 2016-07-13 10:47:36.601000 | 127.0.0.2 | 1966 |
127.0.0.1
Adding to users memtable
[MutationStage-2] | 2016-07-13 10:47:36.601000 | 127.0.0.2 | 2308 |
127.0.0.1
Appending to commitlog
[MutationStage-2] | 2016-07-13 10:47:36.602000 | 127.0.0.3 | 2581 |
127.0.0.1
REQUEST_RESPONSE message received from /127.0.0.2
[MessagingService-Incoming-/127.0.0.2] | 2016-07-13 10:47:36.602000 | 127.0.0.1
| 6584 | 127.0.0.1
Enqueuing response to /127.0.0.1
[MutationStage-2] | 2016-07-13 10:47:36.602000 | 127.0.0.2 | 2693 |
127.0.0.1
Adding to users memtable
[MutationStage-2] | 2016-07-13 10:47:36.602000 | 127.0.0.3 | 2938 |
127.0.0.1
Sending REQUEST_RESPONSE message to /127.0.0.1
[MessagingService-Outgoing-/127.0.0.1] | 2016-07-13 10:47:36.602000 | 127.0.0.2
| 3008 | 127.0.0.1
Enqueuing response to /127.0.0.1
[MutationStage-2] | 2016-07-13 10:47:36.603000 | 127.0.0.3 | 3278 |
127.0.0.1
Processing response from /127.0.0.2
[RequestResponseStage-1] | 2016-07-13 10:47:36.603000 | 127.0.0.1 |
7515 | 127.0.0.1
Sending REQUEST_RESPONSE message to /127.0.0.1
[MessagingService-Outgoing-/127.0.0.1] | 2016-07-13 10:47:36.605000 | 127.0.0.3
| 5241 | 127.0.0.1
REQUEST_RESPONSE message received from /127.0.0.3
[MessagingService-Incoming-/127.0.0.3] | 2016-07-13 10:47:36.605000 | 127.0.0.1
| 9261 | 127.0.0.1
Processing response from /127.0.0.3
[RequestResponseStage-4] | 2016-07-13 10:47:36.605000 | 127.0.0.1 |
9484 | 127.0.0.1
Request
complete | 2016-07-13 10:47:36.605643 | 127.0.0.1 | 9643 | 127.0.0.1
{code}
> dtest failure in cql_tracing_test.TestCqlTracing.tracing_unknown_impl_test
> --------------------------------------------------------------------------
>
> Key: CASSANDRA-11465
> URL: https://issues.apache.org/jira/browse/CASSANDRA-11465
> Project: Cassandra
> Issue Type: Test
> Reporter: Philip Thompson
> Assignee: Jim Witschey
> Labels: dtest
>
> Failing on the following assert, on trunk only:
> {{self.assertEqual(len(errs[0]), 1)}}
> Is not failing consistently.
> example failure:
> http://cassci.datastax.com/job/trunk_dtest/1087/testReport/cql_tracing_test/TestCqlTracing/tracing_unknown_impl_test
> Failed on CassCI build trunk_dtest #1087
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
