|
60 | 60 | except ImportError: |
61 | 61 | pass |
62 | 62 |
|
| 63 | +logger = logging.getLogger(__name__) |
| 64 | + |
63 | 65 |
|
64 | 66 | def test_basic(conn_testaccount): |
65 | 67 | """Basic Connection test.""" |
@@ -1347,6 +1349,176 @@ def test_ocsp_mode_insecure_mode_and_disable_ocsp_checks_mismatch_ocsp_disabled( |
1347 | 1349 | assert "This connection does not perform OCSP checks." in caplog.text |
1348 | 1350 |
|
1349 | 1351 |
|
| 1352 | +def _message_matches_pattern(message, pattern): |
| 1353 | + """Check if a log message matches a pattern (exact match or starts with pattern).""" |
| 1354 | + return message == pattern or message.startswith(pattern) |
| 1355 | + |
| 1356 | + |
| 1357 | +def _find_matching_patterns(messages, patterns): |
| 1358 | + """Find which patterns match the given messages. |
| 1359 | +
|
| 1360 | + Returns: |
| 1361 | + tuple: (matched_patterns, missing_patterns, unmatched_messages) |
| 1362 | + """ |
| 1363 | + matched_patterns = set() |
| 1364 | + unmatched_messages = [] |
| 1365 | + |
| 1366 | + for message in messages: |
| 1367 | + found_match = False |
| 1368 | + for pattern in patterns: |
| 1369 | + if _message_matches_pattern(message, pattern): |
| 1370 | + matched_patterns.add(pattern) |
| 1371 | + found_match = True |
| 1372 | + break |
| 1373 | + if not found_match: |
| 1374 | + unmatched_messages.append(message) |
| 1375 | + |
| 1376 | + missing_patterns = set(patterns) - matched_patterns |
| 1377 | + return matched_patterns, missing_patterns, unmatched_messages |
| 1378 | + |
| 1379 | + |
| 1380 | +def _calculate_log_bytes(messages): |
| 1381 | + """Calculate total byte size of log messages.""" |
| 1382 | + return sum(len(message.encode("utf-8")) for message in messages) |
| 1383 | + |
| 1384 | + |
| 1385 | +def _log_pattern_analysis( |
| 1386 | + actual_messages, |
| 1387 | + expected_patterns, |
| 1388 | + matched_patterns, |
| 1389 | + missing_patterns, |
| 1390 | + unmatched_messages, |
| 1391 | + show_all_messages=False, |
| 1392 | +): |
| 1393 | + """Log detailed analysis of pattern differences. |
| 1394 | +
|
| 1395 | + Args: |
| 1396 | + actual_messages: List of actual log messages |
| 1397 | + expected_patterns: List of expected log patterns |
| 1398 | + matched_patterns: Set of patterns that were found |
| 1399 | + missing_patterns: Set of patterns that were not found |
| 1400 | + unmatched_messages: List of messages that didn't match any pattern |
| 1401 | + show_all_messages: If True, log all actual messages for debugging |
| 1402 | + """ |
| 1403 | + |
| 1404 | + if missing_patterns: |
| 1405 | + logger.warning(f"Missing expected log patterns ({len(missing_patterns)}):") |
| 1406 | + for pattern in sorted(missing_patterns): |
| 1407 | + logger.warning(f" - MISSING: '{pattern}'") |
| 1408 | + |
| 1409 | + if unmatched_messages: |
| 1410 | + logger.warning(f"New/unexpected log messages ({len(unmatched_messages)}):") |
| 1411 | + for message in unmatched_messages: |
| 1412 | + message_bytes = len(message.encode("utf-8")) |
| 1413 | + logger.warning(f" + NEW: '{message}' ({message_bytes} bytes)") |
| 1414 | + |
| 1415 | + # Log summary |
| 1416 | + logger.warning("Log analysis summary:") |
| 1417 | + logger.warning(f" - Expected patterns: {len(expected_patterns)}") |
| 1418 | + logger.warning(f" - Matched patterns: {len(matched_patterns)}") |
| 1419 | + logger.warning(f" - Missing patterns: {len(missing_patterns)}") |
| 1420 | + logger.warning(f" - Actual messages: {len(actual_messages)}") |
| 1421 | + logger.warning(f" - Unmatched messages: {len(unmatched_messages)}") |
| 1422 | + |
| 1423 | + # Show all messages if requested (useful when patterns match but bytes don't) |
| 1424 | + if show_all_messages: |
| 1425 | + logger.warning("All actual log messages:") |
| 1426 | + for i, message in enumerate(actual_messages): |
| 1427 | + message_bytes = len(message.encode("utf-8")) |
| 1428 | + logger.warning(f" [{i:2d}] '{message}' ({message_bytes} bytes)") |
| 1429 | + |
| 1430 | + |
| 1431 | +def _assert_log_bytes_within_tolerance(actual_bytes, expected_bytes, tolerance): |
| 1432 | + """Assert that log bytes are within acceptable tolerance.""" |
| 1433 | + assert actual_bytes == pytest.approx(expected_bytes, rel=tolerance), ( |
| 1434 | + f"Log bytes {actual_bytes} is not approximately equal to expected {expected_bytes} " |
| 1435 | + f"within {tolerance*100}% tolerance. " |
| 1436 | + f"This may indicate unwanted logs being produced or changes in logging behavior." |
| 1437 | + ) |
| 1438 | + |
| 1439 | + |
| 1440 | +@pytest.mark.skipolddriver |
| 1441 | +def test_logs_size_during_basic_query_stays_unchanged(conn_cnx, caplog): |
| 1442 | + """Test that the amount of bytes logged during normal select 1 flow is within acceptable range. Related to: SNOW-2268606""" |
| 1443 | + caplog.set_level(logging.INFO, "snowflake.connector") |
| 1444 | + caplog.clear() |
| 1445 | + |
| 1446 | + # Test-specific constants |
| 1447 | + EXPECTED_BYTES = 145 |
| 1448 | + ACCEPTABLE_DELTA = 0.6 |
| 1449 | + EXPECTED_PATTERNS = [ |
| 1450 | + "Snowflake Connector for Python Version: ", # followed by version info |
| 1451 | + "Connecting to GLOBAL Snowflake domain", |
| 1452 | + ] |
| 1453 | + |
| 1454 | + with conn_cnx() as conn: |
| 1455 | + with conn.cursor() as cur: |
| 1456 | + cur.execute("select 1").fetchall() |
| 1457 | + |
| 1458 | + actual_messages = [record.getMessage() for record in caplog.records] |
| 1459 | + total_log_bytes = _calculate_log_bytes(actual_messages) |
| 1460 | + |
| 1461 | + if total_log_bytes != EXPECTED_BYTES: |
| 1462 | + logger.warning( |
| 1463 | + f"There was a change in a size of the logs produced by the basic Snowflake query. " |
| 1464 | + f"Expected: {EXPECTED_BYTES}, got: {total_log_bytes}. " |
| 1465 | + f"We may need to update the test_logs_size_during_basic_query_stays_unchanged - i.e. EXACT_EXPECTED_LOGS_BYTES constant." |
| 1466 | + ) |
| 1467 | + |
| 1468 | + # Check if patterns match to decide whether to show all messages |
| 1469 | + matched_patterns, missing_patterns, unmatched_messages = ( |
| 1470 | + _find_matching_patterns(actual_messages, EXPECTED_PATTERNS) |
| 1471 | + ) |
| 1472 | + patterns_match_perfectly = ( |
| 1473 | + len(missing_patterns) == 0 and len(unmatched_messages) == 0 |
| 1474 | + ) |
| 1475 | + |
| 1476 | + _log_pattern_analysis( |
| 1477 | + actual_messages, |
| 1478 | + EXPECTED_PATTERNS, |
| 1479 | + matched_patterns, |
| 1480 | + missing_patterns, |
| 1481 | + unmatched_messages, |
| 1482 | + show_all_messages=patterns_match_perfectly, |
| 1483 | + ) |
| 1484 | + |
| 1485 | + _assert_log_bytes_within_tolerance( |
| 1486 | + total_log_bytes, EXPECTED_BYTES, ACCEPTABLE_DELTA |
| 1487 | + ) |
| 1488 | + |
| 1489 | + |
| 1490 | +@pytest.mark.skipolddriver |
| 1491 | +def test_no_new_warnings_or_errors_on_successful_basic_select(conn_cnx, caplog): |
| 1492 | + """Test that the number of warning/error log entries stays the same during successful basic select operations. Related to: SNOW-2268606""" |
| 1493 | + caplog.set_level(logging.WARNING, "snowflake.connector") |
| 1494 | + baseline_warning_count = 0 |
| 1495 | + baseline_error_count = 0 |
| 1496 | + |
| 1497 | + # Execute basic select operations and check counts remain the same |
| 1498 | + caplog.clear() |
| 1499 | + with conn_cnx() as conn: |
| 1500 | + with conn.cursor() as cur: |
| 1501 | + # Execute basic select operations |
| 1502 | + result1 = cur.execute("select 1").fetchall() |
| 1503 | + assert result1 == [(1,)] |
| 1504 | + |
| 1505 | + # Count warning/error log entries after operations |
| 1506 | + test_warning_count = len( |
| 1507 | + [r for r in caplog.records if r.levelno >= logging.WARNING] |
| 1508 | + ) |
| 1509 | + test_error_count = len([r for r in caplog.records if r.levelno >= logging.ERROR]) |
| 1510 | + |
| 1511 | + # Assert counts stay the same (no new warnings or errors) |
| 1512 | + assert test_warning_count == baseline_warning_count, ( |
| 1513 | + f"Warning count increased from {baseline_warning_count} to {test_warning_count}. " |
| 1514 | + f"New warnings: {[r.getMessage() for r in caplog.records if r.levelno == logging.WARNING]}" |
| 1515 | + ) |
| 1516 | + assert test_error_count == baseline_error_count, ( |
| 1517 | + f"Error count increased from {baseline_error_count} to {test_error_count}. " |
| 1518 | + f"New errors: {[r.getMessage() for r in caplog.records if r.levelno >= logging.ERROR]}" |
| 1519 | + ) |
| 1520 | + |
| 1521 | + |
1350 | 1522 | @pytest.mark.skipolddriver |
1351 | 1523 | def test_ocsp_mode_insecure_mode_and_disable_ocsp_checks_mismatch_ocsp_enabled( |
1352 | 1524 | conn_cnx, is_public_test, is_local_dev_setup, caplog |
|
0 commit comments