Coverage for app/services/packer_executor.py: 100.00%

1""" 

2Packer execution utilities with comprehensive structured logging. 

3 

4``init`` and ``build`` stream their output line-by-line via 

5``_stream_subprocess`` so the deploy task's per-deployment logger can ship 

6each line onto the Celery event bus while the build is still running. 

7``validate`` is short and stays as a buffered call. 

8""" 

9 

10import json 

11import os 

12import subprocess 

13from typing import Any 

14 

15from ..config import settings 

16from ..utils.logger import LogCategory, get_logger 

17from .terraform_executor import OutputCallback, _stream_subprocess 

18 

19logger = get_logger(__name__) 

20 

21 

22class PackerExecutor: 

23 """Executor for Packer operations with detailed logging. 

24 

25 ``output_callback`` is optional; when set, each line of subprocess 

26 output is fed to it as it arrives. Used by the deploy task to forward 

27 Packer build output onto the Celery event bus during long builds. 

28 """ 

29 

30 def __init__( 

31 self, 

32 working_dir: str, 

33 env_vars: dict[str, str] | None = None, 

34 output_callback: OutputCallback | None = None, 

35 ): 

36 self.working_dir = working_dir 

37 self.packer_path = settings.PACKER_PATH 

38 self.env_vars = env_vars or {} 

39 self.output_callback = output_callback 

40 

41 def _get_env(self, extra_env: dict[str, str] | None = None) -> dict[str, str]: 

42 """Get environment variables including OpenStack credentials and Packer debug logging.""" 

43 env = os.environ.copy() 

44 env.update(self.env_vars) 

45 if extra_env: 

46 env.update(extra_env) 

47 env["PACKER_LOG"] = "1" 

48 return env 

49 

50 def init(self) -> tuple[bool, str, str]: 

51 """Initialize Packer (install required plugins). Streams output.""" 

52 logger.operation_start("packer_init", working_dir=self.working_dir) 

53 try: 

54 cmd = [self.packer_path, "init", "."] 

55 logger.debug(f"[Packer] Running command: {' '.join(cmd)}") 

56 returncode, stdout, stderr = _stream_subprocess( 

57 cmd, 

58 cwd=self.working_dir, 

59 env=self._get_env(), 

60 timeout=300, 

61 tool_name="packer_init", 

62 output_callback=self.output_callback, 

63 ) 

64 success = returncode == 0 

65 

66 if stdout: 

67 logger.command_output("packer_init", stdout, returncode) 

68 

69 if not success: 

70 if returncode == 124: 

71 logger.error("Packer init timed out after 5 minutes", category=LogCategory.ERROR) 

72 else: 

73 logger.error( 

74 "Packer init failed", 

75 category=LogCategory.ERROR, 

76 returncode=returncode, 

77 ) 

78 else: 

79 logger.success("Packer init completed", category=LogCategory.STATUS) 

80 

81 logger.operation_end("packer_init", success) 

82 return success, stdout, stderr 

83 except Exception as e: 

84 logger.exception("Packer init failed with exception", exception=e) 

85 logger.operation_end("packer_init", success=False) 

86 return False, "", str(e) 

87 

88 def validate(self, template_file: str, variables: dict[str, Any] | None = None) -> tuple[bool, str, str]: 

89 """Validate a Packer template (short, buffered).""" 

90 logger.operation_start("packer_validate", template=template_file) 

91 logger.debug(f"Packer working directory: {self.working_dir}", category=LogCategory.SYSTEM) 

92 try: 

93 cmd = [self.packer_path, "validate"] 

94 if variables: 

95 for key, value in variables.items(): 

96 value_str = json.dumps(value) if isinstance(value, list | dict) else str(value) 

97 cmd.extend(["-var", f"{key}={value_str}"]) 

98 cmd.append(".") 

99 

100 logger.debug(f"[Packer] Running command: {' '.join(cmd)}") 

101 result = subprocess.run( 

102 cmd, cwd=self.working_dir, capture_output=True, text=True, timeout=60, env=self._get_env() 

103 ) 

104 success = result.returncode == 0 

105 

106 if result.stdout: 

107 logger.command_output("packer_validate", result.stdout, result.returncode) 

108 

109 if not success: 

110 error_msg = self._extract_error_from_packer(result.stderr) 

111 logger.error( 

112 f"Packer validation failed: {error_msg}", 

113 category=LogCategory.ERROR, 

114 returncode=result.returncode, 

115 stderr=result.stderr[:1000], 

116 ) 

117 else: 

118 logger.success("Packer template validated", category=LogCategory.STATUS) 

119 

120 logger.operation_end("packer_validate", success) 

121 return success, result.stdout, result.stderr 

122 except Exception as e: 

123 logger.exception("Packer validation failed with exception", exception=e) 

124 logger.operation_end("packer_validate", success=False) 

125 return False, "", str(e) 

126 

127 def build( 

128 self, 

129 template_file: str, 

130 variables: dict[str, Any] | None = None, 

131 extra_env: dict[str, str] | None = None, 

132 force: bool = True, 

133 ) -> tuple[bool, str]: 

134 """Build a Packer image. Streams output line-by-line.""" 

135 logger.operation_start("packer_build", template=template_file, force=force, var_count=len(variables or {})) 

136 try: 

137 cmd = [self.packer_path, "build"] 

138 if force: 

139 cmd.append("-force") 

140 

141 if variables: 

142 for key, value in variables.items(): 

143 value_str = json.dumps(value) if isinstance(value, list | dict) else str(value) 

144 cmd.extend(["-var", f"{key}={value_str}"]) 

145 cmd.append(".") 

146 

147 logger.info( 

148 "Starting Packer build process (this may take several minutes)...", 

149 category=LogCategory.STATUS, 

150 ) 

151 logger.debug(f"[Packer] Running command: {' '.join(cmd)}") 

152 

153 returncode, stdout, _ = _stream_subprocess( 

154 cmd, 

155 cwd=self.working_dir, 

156 env=self._get_env(extra_env), 

157 timeout=3600, 

158 tool_name="packer_build", 

159 output_callback=self.output_callback, 

160 ) 

161 success = returncode == 0 

162 output_lines_count = stdout.count("\n") + 1 if stdout else 0 

163 

164 if not success: 

165 if returncode == 124: 

166 logger.error("Packer build timed out after 1 hour", category=LogCategory.ERROR) 

167 else: 

168 logger.error( 

169 "Packer build failed", 

170 category=LogCategory.ERROR, 

171 returncode=returncode, 

172 output_lines=output_lines_count, 

173 ) 

174 else: 

175 logger.success( 

176 "Packer build completed successfully", 

177 category=LogCategory.STATUS, 

178 output_lines=output_lines_count, 

179 ) 

180 

181 logger.operation_end("packer_build", success) 

182 return success, stdout 

183 except Exception as e: 

184 logger.exception("Packer build failed with exception", exception=e) 

185 logger.operation_end("packer_build", success=False) 

186 return False, str(e) 

187 

188 def _extract_error_from_packer(self, stderr: str) -> str: 

189 """Extract a meaningful error message from Packer stderr. 

190 

191 Packer stderr contains a lot of TRACE/DEBUG noise; we filter that 

192 and pull out lines that look like actual errors. 

193 """ 

194 lines = stderr.split("\n") 

195 errors = [] 

196 for line in lines: 

197 if "[TRACE]" in line or "[DEBUG]" in line or "plugingetter" in line: 

198 continue 

199 if "* Get" in line or "Error" in line or "error" in line or line.strip().startswith("*"): 

200 errors.append(line.strip()) 

201 

202 if errors: 

203 return " | ".join(errors[:3]) 

204 

205 for line in reversed(lines): 

206 if line.strip() and "[TRACE]" not in line and "[DEBUG]" not in line: 

207 return line.strip() 

208 return "Unknown error"