cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Philip Thompson (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CASSANDRA-11598) dtest failure in cql_tracing_test.TestCqlTracing.tracing_simple_test
Date Tue, 19 Apr 2016 20:01:25 GMT

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

Philip Thompson commented on CASSANDRA-11598:
---------------------------------------------

Doesn't happen on 2.2. Definitely a 2.1 only problem.

http://cassci.datastax.com/view/Parameterized/job/parameterized_dtest_multiplexer/73/

> dtest failure in cql_tracing_test.TestCqlTracing.tracing_simple_test
> --------------------------------------------------------------------
>
>                 Key: CASSANDRA-11598
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-11598
>             Project: Cassandra
>          Issue Type: Test
>            Reporter: Jim Witschey
>            Assignee: Philip Thompson
>              Labels: dtest
>
> example failure:
> http://cassci.datastax.com/job/cassandra-2.1_offheap_dtest/330/testReport/cql_tracing_test/TestCqlTracing/tracing_simple_test
> Failed on CassCI build cassandra-2.1_offheap_dtest #330 - 2.1.14-tentative
> {{' 127.0.0.2 '}} isn't in the trace, but it looks like {{'\127.0.0.2 '}} is -- should
we change the regex here?
> {code}
> Error Message
> ' 127.0.0.2 ' not found in 'Consistency level set to ALL.\nNow Tracing is enabled\n\n
firstname | lastname\n-----------+----------\n     Frodo |  Baggins\n\n(1 rows)\n\nTracing
session: 0268da20-0328-11e6-b014-53144f0dba91\n\n activity                               
                                                                                    | timestamp
                 | source    | source_elapsed\n-----------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------\n
                                                                                         
               Execute CQL3 query | 2016-04-15 16:35:05.538000 | 127.0.0.1 |             
0\n                                                READ message received from /127.0.0.1 [MessagingService-Incoming-/127.0.0.1]
| 2016-04-15 16:35:05.540000 | 127.0.0.3 |             47\n Parsing SELECT firstname, lastname
FROM ks.users WHERE userid = 550e8400-e29b-41d4-a716-446655440000; [SharedPool-Worker-2] |
2016-04-15 16:35:05.540000 | 127.0.0.1 |             88\n                                
                                                  Preparing statement [SharedPool-Worker-2]
| 2016-04-15 16:35:05.540000 | 127.0.0.1 |            355\n                              
                                         reading digest from /127.0.0.2 [SharedPool-Worker-2]
| 2016-04-15 16:35:05.542000 | 127.0.0.1 |           1245\n                              
                              Executing single-partition query on users [SharedPool-Worker-3]
| 2016-04-15 16:35:05.542000 | 127.0.0.1 |           1249\n                              
                                           Acquiring sstable references [SharedPool-Worker-3]
| 2016-04-15 16:35:05.545000 | 127.0.0.1 |           1265\n                              
                              Executing single-partition query on users [SharedPool-Worker-1]
| 2016-04-15 16:35:05.546000 | 127.0.0.3 |            369\n                              
                                            Merging memtable tombstones [SharedPool-Worker-3]
| 2016-04-15 16:35:05.546000 | 127.0.0.1 |           1302\n                              
                                         reading digest from /127.0.0.3 [SharedPool-Worker-2]
| 2016-04-15 16:35:05.547000 | 127.0.0.1 |           1338\n                             Skipped
0/0 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-3] |
2016-04-15 16:35:05.548000 | 127.0.0.1 |           1403\n                                
                                         Acquiring sstable references [SharedPool-Worker-1]
| 2016-04-15 16:35:05.549000 | 127.0.0.3 |            392\n                              
                             Merging data from memtables and 0 sstables [SharedPool-Worker-3]
| 2016-04-15 16:35:05.549000 | 127.0.0.1 |           1428\n                              
                                      Read 1 live and 0 tombstone cells [SharedPool-Worker-3]
| 2016-04-15 16:35:05.550000 | 127.0.0.1 |           1509\n                              
                    Sending READ message to /127.0.0.3 [MessagingService-Outgoing-/127.0.0.3]
| 2016-04-15 16:35:05.550000 | 127.0.0.1 |           1780\n                              
                    Sending READ message to /127.0.0.2 [MessagingService-Outgoing-/127.0.0.2]
| 2016-04-15 16:35:05.551000 | 127.0.0.1 |           3748\n                              
     REQUEST_RESPONSE message received from /127.0.0.3 [MessagingService-Incoming-/127.0.0.3]
| 2016-04-15 16:35:05.552000 | 127.0.0.1 |           4454\n                              
                                            Merging memtable tombstones [SharedPool-Worker-1]
| 2016-04-15 16:35:05.553000 | 127.0.0.3 |            453\n                              
                                    Processing response from /127.0.0.3 [SharedPool-Worker-4]
| 2016-04-15 16:35:05.553000 | 127.0.0.1 |           5110\n                              
     REQUEST_RESPONSE message received from /127.0.0.2 [MessagingService-Incoming-/127.0.0.2]
| 2016-04-15 16:35:05.554000 | 127.0.0.1 |           6892\n                              
                                    Processing response from /127.0.0.2 [SharedPool-Worker-4]
| 2016-04-15 16:35:05.555000 | 127.0.0.1 |           7099\n                             Skipped
0/0 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-1] |
2016-04-15 16:35:05.556000 | 127.0.0.3 |            596\n                                
                           Merging data from memtables and 0 sstables [SharedPool-Worker-1]
| 2016-04-15 16:35:05.559000 | 127.0.0.3 |            620\n                              
                                      Read 1 live and 0 tombstone cells [SharedPool-Worker-1]
| 2016-04-15 16:35:05.560000 | 127.0.0.3 |            741\n                              
                                       Enqueuing response to /127.0.0.1 [SharedPool-Worker-1]
| 2016-04-15 16:35:05.562000 | 127.0.0.3 |           1265\n                              
        Sending REQUEST_RESPONSE message to /127.0.0.1 [MessagingService-Outgoing-/127.0.0.1]
| 2016-04-15 16:35:05.564000 | 127.0.0.3 |           1892\n                              
                                                                             Request complete
| 2016-04-15 16:35:05.545435 | 127.0.0.1 |           7435\n\n\n'
> -------------------- >> begin captured logging << --------------------
> dtest: DEBUG: cluster ccm directory: /mnt/tmp/dtest-hfIRwY
> dtest: DEBUG: Custom init_config not found. Setting defaults.
> dtest: DEBUG: Done setting configuration options:
> {   'initial_token': None,
>     'memtable_allocation_type': 'offheap_objects',
>     '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
>  firstname | lastname
> -----------+----------
>      Frodo |  Baggins
> (1 rows)
> Tracing session: 0268da20-0328-11e6-b014-53144f0dba91
>  activity                                                                           
                                        | timestamp                  | source    | source_elapsed
> -----------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------
>                                                                                     
                     Execute CQL3 query | 2016-04-15 16:35:05.538000 | 127.0.0.1 |       
      0
>                                                 READ message received from /127.0.0.1
[MessagingService-Incoming-/127.0.0.1] | 2016-04-15 16:35:05.540000 | 127.0.0.3 |        
    47
>  Parsing SELECT firstname, lastname FROM ks.users WHERE userid = 550e8400-e29b-41d4-a716-446655440000;
[SharedPool-Worker-2] | 2016-04-15 16:35:05.540000 | 127.0.0.1 |             88
>                                                                                    Preparing
statement [SharedPool-Worker-2] | 2016-04-15 16:35:05.540000 | 127.0.0.1 |            355
>                                                                         reading digest
from /127.0.0.2 [SharedPool-Worker-2] | 2016-04-15 16:35:05.542000 | 127.0.0.1 |         
 1245
>                                                              Executing single-partition
query on users [SharedPool-Worker-3] | 2016-04-15 16:35:05.542000 | 127.0.0.1 |          
1249
>                                                                           Acquiring sstable
references [SharedPool-Worker-3] | 2016-04-15 16:35:05.545000 | 127.0.0.1 |           1265
>                                                              Executing single-partition
query on users [SharedPool-Worker-1] | 2016-04-15 16:35:05.546000 | 127.0.0.3 |          
 369
>                                                                            Merging memtable
tombstones [SharedPool-Worker-3] | 2016-04-15 16:35:05.546000 | 127.0.0.1 |           1302
>                                                                         reading digest
from /127.0.0.3 [SharedPool-Worker-2] | 2016-04-15 16:35:05.547000 | 127.0.0.1 |         
 1338
>                              Skipped 0/0 non-slice-intersecting sstables, included 0
due to tombstones [SharedPool-Worker-3] | 2016-04-15 16:35:05.548000 | 127.0.0.1 |       
   1403
>                                                                           Acquiring sstable
references [SharedPool-Worker-1] | 2016-04-15 16:35:05.549000 | 127.0.0.3 |            392
>                                                             Merging data from memtables
and 0 sstables [SharedPool-Worker-3] | 2016-04-15 16:35:05.549000 | 127.0.0.1 |          
1428
>                                                                      Read 1 live and
0 tombstone cells [SharedPool-Worker-3] | 2016-04-15 16:35:05.550000 | 127.0.0.1 |       
   1509
>                                                    Sending READ message to /127.0.0.3
[MessagingService-Outgoing-/127.0.0.3] | 2016-04-15 16:35:05.550000 | 127.0.0.1 |        
  1780
>                                                    Sending READ message to /127.0.0.2
[MessagingService-Outgoing-/127.0.0.2] | 2016-04-15 16:35:05.551000 | 127.0.0.1 |        
  3748
>                                     REQUEST_RESPONSE message received from /127.0.0.3
[MessagingService-Incoming-/127.0.0.3] | 2016-04-15 16:35:05.552000 | 127.0.0.1 |        
  4454
>                                                                            Merging memtable
tombstones [SharedPool-Worker-1] | 2016-04-15 16:35:05.553000 | 127.0.0.3 |            453
>                                                                    Processing response
from /127.0.0.3 [SharedPool-Worker-4] | 2016-04-15 16:35:05.553000 | 127.0.0.1 |         
 5110
>                                     REQUEST_RESPONSE message received from /127.0.0.2
[MessagingService-Incoming-/127.0.0.2] | 2016-04-15 16:35:05.554000 | 127.0.0.1 |        
  6892
>                                                                    Processing response
from /127.0.0.2 [SharedPool-Worker-4] | 2016-04-15 16:35:05.555000 | 127.0.0.1 |         
 7099
>                              Skipped 0/0 non-slice-intersecting sstables, included 0
due to tombstones [SharedPool-Worker-1] | 2016-04-15 16:35:05.556000 | 127.0.0.3 |       
    596
>                                                             Merging data from memtables
and 0 sstables [SharedPool-Worker-1] | 2016-04-15 16:35:05.559000 | 127.0.0.3 |          
 620
>                                                                      Read 1 live and
0 tombstone cells [SharedPool-Worker-1] | 2016-04-15 16:35:05.560000 | 127.0.0.3 |       
    741
>                                                                       Enqueuing response
to /127.0.0.1 [SharedPool-Worker-1] | 2016-04-15 16:35:05.562000 | 127.0.0.3 |           1265
>                                        Sending REQUEST_RESPONSE message to /127.0.0.1
[MessagingService-Outgoing-/127.0.0.1] | 2016-04-15 16:35:05.564000 | 127.0.0.3 |        
  1892
>                                                                                     
                       Request complete | 2016-04-15 16:35:05.545435 | 127.0.0.1 |       
   7435
> --------------------- >> end captured logging << ---------------------
> Stacktrace
>   File "/usr/lib/python2.7/unittest/case.py", line 329, in run
>     testMethod()
>   File "/home/automaton/cassandra-dtest/cql_tracing_test.py", line 97, in tracing_simple_test
>     self.trace(session)
>   File "/home/automaton/cassandra-dtest/cql_tracing_test.py", line 85, in trace
>     self.assertIn(' 127.0.0.2 ', 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.2 ' not found in 'Consistency level set to ALL.\\nNow Tracing is enabled\\n\\n
firstname | lastname\\n-----------+----------\\n     Frodo |  Baggins\\n\\n(1 rows)\\n\\nTracing
session: 0268da20-0328-11e6-b014-53144f0dba91\\n\\n activity                             
                                                                                      | timestamp
                 | source    | source_elapsed\\n-----------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------\\n
                                                                                         
               Execute CQL3 query | 2016-04-15 16:35:05.538000 | 127.0.0.1 |             
0\\n                                                READ message received from /127.0.0.1
[MessagingService-Incoming-/127.0.0.1] | 2016-04-15 16:35:05.540000 | 127.0.0.3 |        
    47\\n Parsing SELECT firstname, lastname FROM ks.users WHERE userid = 550e8400-e29b-41d4-a716-446655440000;
[SharedPool-Worker-2] | 2016-04-15 16:35:05.540000 | 127.0.0.1 |             88\\n       
                                                                           Preparing statement
[SharedPool-Worker-2] | 2016-04-15 16:35:05.540000 | 127.0.0.1 |            355\\n       
                                                                reading digest from /127.0.0.2
[SharedPool-Worker-2] | 2016-04-15 16:35:05.542000 | 127.0.0.1 |           1245\\n       
                                                     Executing single-partition query on users
[SharedPool-Worker-3] | 2016-04-15 16:35:05.542000 | 127.0.0.1 |           1249\\n       
                                                                  Acquiring sstable references
[SharedPool-Worker-3] | 2016-04-15 16:35:05.545000 | 127.0.0.1 |           1265\\n       
                                                     Executing single-partition query on users
[SharedPool-Worker-1] | 2016-04-15 16:35:05.546000 | 127.0.0.3 |            369\\n       
                                                                   Merging memtable tombstones
[SharedPool-Worker-3] | 2016-04-15 16:35:05.546000 | 127.0.0.1 |           1302\\n       
                                                                reading digest from /127.0.0.3
[SharedPool-Worker-2] | 2016-04-15 16:35:05.547000 | 127.0.0.1 |           1338\\n       
                     Skipped 0/0 non-slice-intersecting sstables, included 0 due to tombstones
[SharedPool-Worker-3] | 2016-04-15 16:35:05.548000 | 127.0.0.1 |           1403\\n       
                                                                  Acquiring sstable references
[SharedPool-Worker-1] | 2016-04-15 16:35:05.549000 | 127.0.0.3 |            392\\n       
                                                    Merging data from memtables and 0 sstables
[SharedPool-Worker-3] | 2016-04-15 16:35:05.549000 | 127.0.0.1 |           1428\\n       
                                                             Read 1 live and 0 tombstone cells
[SharedPool-Worker-3] | 2016-04-15 16:35:05.550000 | 127.0.0.1 |           1509\\n       
                                           Sending READ message to /127.0.0.3 [MessagingService-Outgoing-/127.0.0.3]
| 2016-04-15 16:35:05.550000 | 127.0.0.1 |           1780\\n                             
                     Sending READ message to /127.0.0.2 [MessagingService-Outgoing-/127.0.0.2]
| 2016-04-15 16:35:05.551000 | 127.0.0.1 |           3748\\n                             
      REQUEST_RESPONSE message received from /127.0.0.3 [MessagingService-Incoming-/127.0.0.3]
| 2016-04-15 16:35:05.552000 | 127.0.0.1 |           4454\\n                             
                                             Merging memtable tombstones [SharedPool-Worker-1]
| 2016-04-15 16:35:05.553000 | 127.0.0.3 |            453\\n                             
                                     Processing response from /127.0.0.3 [SharedPool-Worker-4]
| 2016-04-15 16:35:05.553000 | 127.0.0.1 |           5110\\n                             
      REQUEST_RESPONSE message received from /127.0.0.2 [MessagingService-Incoming-/127.0.0.2]
| 2016-04-15 16:35:05.554000 | 127.0.0.1 |           6892\\n                             
                                     Processing response from /127.0.0.2 [SharedPool-Worker-4]
| 2016-04-15 16:35:05.555000 | 127.0.0.1 |           7099\\n                             Skipped
0/0 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-1] |
2016-04-15 16:35:05.556000 | 127.0.0.3 |            596\\n                               
                            Merging data from memtables and 0 sstables [SharedPool-Worker-1]
| 2016-04-15 16:35:05.559000 | 127.0.0.3 |            620\\n                             
                                       Read 1 live and 0 tombstone cells [SharedPool-Worker-1]
| 2016-04-15 16:35:05.560000 | 127.0.0.3 |            741\\n                             
                                        Enqueuing response to /127.0.0.1 [SharedPool-Worker-1]
| 2016-04-15 16:35:05.562000 | 127.0.0.3 |           1265\\n                             
         Sending REQUEST_RESPONSE message to /127.0.0.1 [MessagingService-Outgoing-/127.0.0.1]
| 2016-04-15 16:35:05.564000 | 127.0.0.3 |           1892\\n                             
                                                                              Request complete
| 2016-04-15 16:35:05.545435 | 127.0.0.1 |           7435\\n\\n\\n'\n--------------------
>> begin captured logging << --------------------\ndtest: DEBUG: cluster ccm directory:
/mnt/tmp/dtest-hfIRwY\ndtest: DEBUG: Custom init_config not found. Setting defaults.\ndtest:
DEBUG: Done setting configuration options:\n{   'initial_token': None,\n    'memtable_allocation_type':
'offheap_objects',\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\n firstname | lastname\n-----------+----------\n
    Frodo |  Baggins\n\n(1 rows)\n\nTracing session: 0268da20-0328-11e6-b014-53144f0dba91\n\n
activity                                                                                 
                                  | timestamp                  | source    | source_elapsed\n-----------------------------------------------------------------------------------------------------------------------------+----------------------------+-----------+----------------\n
                                                                                         
               Execute CQL3 query | 2016-04-15 16:35:05.538000 | 127.0.0.1 |             
0\n                                                READ message received from /127.0.0.1 [MessagingService-Incoming-/127.0.0.1]
| 2016-04-15 16:35:05.540000 | 127.0.0.3 |             47\n Parsing SELECT firstname, lastname
FROM ks.users WHERE userid = 550e8400-e29b-41d4-a716-446655440000; [SharedPool-Worker-2] |
2016-04-15 16:35:05.540000 | 127.0.0.1 |             88\n                                
                                                  Preparing statement [SharedPool-Worker-2]
| 2016-04-15 16:35:05.540000 | 127.0.0.1 |            355\n                              
                                         reading digest from /127.0.0.2 [SharedPool-Worker-2]
| 2016-04-15 16:35:05.542000 | 127.0.0.1 |           1245\n                              
                              Executing single-partition query on users [SharedPool-Worker-3]
| 2016-04-15 16:35:05.542000 | 127.0.0.1 |           1249\n                              
                                           Acquiring sstable references [SharedPool-Worker-3]
| 2016-04-15 16:35:05.545000 | 127.0.0.1 |           1265\n                              
                              Executing single-partition query on users [SharedPool-Worker-1]
| 2016-04-15 16:35:05.546000 | 127.0.0.3 |            369\n                              
                                            Merging memtable tombstones [SharedPool-Worker-3]
| 2016-04-15 16:35:05.546000 | 127.0.0.1 |           1302\n                              
                                         reading digest from /127.0.0.3 [SharedPool-Worker-2]
| 2016-04-15 16:35:05.547000 | 127.0.0.1 |           1338\n                             Skipped
0/0 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-3] |
2016-04-15 16:35:05.548000 | 127.0.0.1 |           1403\n                                
                                         Acquiring sstable references [SharedPool-Worker-1]
| 2016-04-15 16:35:05.549000 | 127.0.0.3 |            392\n                              
                             Merging data from memtables and 0 sstables [SharedPool-Worker-3]
| 2016-04-15 16:35:05.549000 | 127.0.0.1 |           1428\n                              
                                      Read 1 live and 0 tombstone cells [SharedPool-Worker-3]
| 2016-04-15 16:35:05.550000 | 127.0.0.1 |           1509\n                              
                    Sending READ message to /127.0.0.3 [MessagingService-Outgoing-/127.0.0.3]
| 2016-04-15 16:35:05.550000 | 127.0.0.1 |           1780\n                              
                    Sending READ message to /127.0.0.2 [MessagingService-Outgoing-/127.0.0.2]
| 2016-04-15 16:35:05.551000 | 127.0.0.1 |           3748\n                              
     REQUEST_RESPONSE message received from /127.0.0.3 [MessagingService-Incoming-/127.0.0.3]
| 2016-04-15 16:35:05.552000 | 127.0.0.1 |           4454\n                              
                                            Merging memtable tombstones [SharedPool-Worker-1]
| 2016-04-15 16:35:05.553000 | 127.0.0.3 |            453\n                              
                                    Processing response from /127.0.0.3 [SharedPool-Worker-4]
| 2016-04-15 16:35:05.553000 | 127.0.0.1 |           5110\n                              
     REQUEST_RESPONSE message received from /127.0.0.2 [MessagingService-Incoming-/127.0.0.2]
| 2016-04-15 16:35:05.554000 | 127.0.0.1 |           6892\n                              
                                    Processing response from /127.0.0.2 [SharedPool-Worker-4]
| 2016-04-15 16:35:05.555000 | 127.0.0.1 |           7099\n                             Skipped
0/0 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-1] |
2016-04-15 16:35:05.556000 | 127.0.0.3 |            596\n                                
                           Merging data from memtables and 0 sstables [SharedPool-Worker-1]
| 2016-04-15 16:35:05.559000 | 127.0.0.3 |            620\n                              
                                      Read 1 live and 0 tombstone cells [SharedPool-Worker-1]
| 2016-04-15 16:35:05.560000 | 127.0.0.3 |            741\n                              
                                       Enqueuing response to /127.0.0.1 [SharedPool-Worker-1]
| 2016-04-15 16:35:05.562000 | 127.0.0.3 |           1265\n                              
        Sending REQUEST_RESPONSE message to /127.0.0.1 [MessagingService-Outgoing-/127.0.0.1]
| 2016-04-15 16:35:05.564000 | 127.0.0.3 |           1892\n                              
                                                                             Request complete
| 2016-04-15 16:35:05.545435 | 127.0.0.1 |           7435\n\n\n\n--------------------- >>
end captured logging << ---------------------"
> Standard Output
> (EE)  (EE)  (EE)  (EE)  
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message