|
1 | 1 | """Integration tests for sam local callback commands - edge cases only.""" |
2 | 2 |
|
| 3 | +import logging |
3 | 4 | import re |
4 | 5 | from pathlib import Path |
5 | 6 |
|
|
11 | 12 | from tests.integration.durable_function_examples import DurableFunctionExamples |
12 | 13 | from tests.testing_utils import run_command |
13 | 14 |
|
| 15 | +LOG = logging.getLogger(__name__) |
| 16 | + |
14 | 17 |
|
15 | 18 | @pytest.mark.xdist_group(name="durable") |
16 | 19 | class TestLocalCallback(DurableIntegBase, InvokeIntegBase): |
@@ -41,31 +44,54 @@ def _do_callback_test(self, action, operation_name, callback_type, error_suffix) |
41 | 44 | command_list = self.get_invoke_command_list( |
42 | 45 | example.function_name, no_event=True, durable_execution_name=execution_name |
43 | 46 | ) |
| 47 | + LOG.info("Starting invoke command: %s", " ".join(command_list)) |
44 | 48 | process, output_lines, thread = self.start_command_with_streaming( |
45 | 49 | command_list, f"test_callback_already_completed_{action}" |
46 | 50 | ) |
47 | 51 |
|
48 | 52 | # Wait for callback ID |
| 53 | + LOG.info("Waiting for callback ID from streaming output...") |
49 | 54 | callback_id = self.wait_for_callback_id(output_lines) |
50 | | - self.assertIsNotNone(callback_id, "Failed to get callback ID from output") |
| 55 | + LOG.info("Callback ID result: %s, output_lines collected: %d", callback_id, len(output_lines)) |
| 56 | + if not callback_id: |
| 57 | + LOG.error("Failed to get callback ID. Output lines so far: %s", output_lines) |
| 58 | + # Also capture process state |
| 59 | + LOG.error("Process poll() = %s", process.poll()) |
| 60 | + self.assertIsNotNone(callback_id, f"Failed to get callback ID from output. Lines: {output_lines}") |
51 | 61 |
|
52 | 62 | # Send first callback to complete the execution |
53 | 63 | succeed_command = self.get_callback_command_list("succeed", callback_id, result="test result") |
| 64 | + LOG.info("Sending first callback: %s", " ".join(succeed_command)) |
54 | 65 | result = run_command(succeed_command) |
55 | | - self.assertEqual(result.process.returncode, 0) |
| 66 | + stdout_str = result.stdout.decode("utf-8") if isinstance(result.stdout, bytes) else result.stdout |
| 67 | + stderr_str = result.stderr.decode("utf-8") if isinstance(result.stderr, bytes) else result.stderr |
| 68 | + LOG.info( |
| 69 | + "First callback result: returncode=%d, stdout=%s, stderr=%s", |
| 70 | + result.process.returncode, |
| 71 | + stdout_str, |
| 72 | + stderr_str, |
| 73 | + ) |
| 74 | + self.assertEqual( |
| 75 | + result.process.returncode, 0, f"First callback failed: stdout={stdout_str}, stderr={stderr_str}" |
| 76 | + ) |
56 | 77 |
|
57 | 78 | # Wait for process to complete and close file handles |
| 79 | + LOG.info("Waiting for invoke process to complete...") |
58 | 80 | process.wait(timeout=30) |
59 | 81 | thread.join(timeout=5) |
60 | 82 | if process.stdin: |
61 | 83 | process.stdin.close() |
62 | 84 | if process.stdout: |
63 | 85 | process.stdout.close() |
| 86 | + LOG.info("Invoke process completed with returncode=%d", process.returncode) |
64 | 87 |
|
65 | 88 | # Try to send another callback (should fail) |
66 | 89 | second_command = self.get_callback_command_list(action, callback_id) |
| 90 | + LOG.info("Sending second callback (should fail): %s", " ".join(second_command)) |
67 | 91 | result = run_command(second_command) |
68 | 92 | stderr_str = result.stderr.decode("utf-8") if isinstance(result.stderr, bytes) else result.stderr |
| 93 | + stderr_str = stderr_str.replace("\r\n", "\n") |
| 94 | + LOG.info("Second callback result: returncode=%d, stderr=%s", result.process.returncode, stderr_str) |
69 | 95 |
|
70 | 96 | self.assertNotEqual(result.process.returncode, 0) |
71 | 97 | expected_pattern = f"Error: An error occurred \\(404\\) when calling the {operation_name} operation: Failed to process callback {callback_type}: Callback .+ {error_suffix}" |
|
0 commit comments