cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jim Witschey (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CASSANDRA-11598) dtest failure in cql_tracing_test.TestCqlTracing.tracing_simple_test
Date Mon, 18 Apr 2016 20:53:25 GMT
Jim Witschey created CASSANDRA-11598:
----------------------------------------

             Summary: 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: DS Test Eng


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