Deployment and lifecycle management for Nix
0
fork

Configure Feed

Select the types of activity you want to include in your feed.

agent: include more context in uploaded log

+298 -9
+47 -6
apps/sower_agent/lib/sower_agent/deployer.ex
··· 12 12 alias SowerClient.Storage.DeploymentLogUploadRequest 13 13 14 14 def run(%Deployment{} = deployment) do 15 + run_with_opts(deployment, upgrade_opts: [], reboot_opts: []) 16 + end 17 + 18 + def run_with_opts(%Deployment{} = deployment, opts) do 19 + upgrade_opts = Keyword.get(opts, :upgrade_opts, []) 20 + reboot_opts = Keyword.get(opts, :reboot_opts, []) 21 + write_log_fun = Keyword.get(upgrade_opts, :write_log_fun, &maybe_write_log/3) 22 + 15 23 result = 16 24 deployment 17 - |> upgrade() 25 + |> upgrade(upgrade_opts) 18 26 |> deployment_result() 19 27 20 - maybe_reboot(deployment, result) 28 + maybe_reboot(deployment, result, [{:write_log_fun, write_log_fun} | reboot_opts]) 21 29 result 22 30 end 23 31 ··· 74 82 |> async_stream_fun.(fn 75 83 {:ok, {:ok, %SeedDeployment{seed: seed} = seed_deploy}} -> 76 84 profile = get_deployment_profile_fun.(seed_deploy.subscription_sid) 85 + mode = SowerAgent.Seed.activation_mode(profile) 86 + 87 + preamble = [ 88 + decision_line("realized #{seed.name} (#{seed.seed_type})"), 89 + decision_line("activating #{seed.name} (#{seed.seed_type}) with mode: #{mode}") 90 + ] 77 91 78 92 Logger.info( 79 93 msg: "Activating seed", ··· 95 109 seed_sid: seed.sid 96 110 ) 97 111 98 - write_log_fun.(deployment, seed, output) 112 + write_log_fun.(deployment, seed, preamble ++ output) 99 113 100 114 {:error, _code, output} -> 101 115 Logger.error( ··· 104 118 seed_sid: seed.sid 105 119 ) 106 120 107 - write_log_fun.(deployment, seed, output) 121 + write_log_fun.(deployment, seed, preamble ++ output) 108 122 109 123 {:error, reason} when reason in [:activator_unavailable, :cmd_not_found] -> 110 124 Logger.error( ··· 114 128 reason: inspect(reason) 115 129 ) 116 130 117 - write_log_fun.(deployment, seed, [ 131 + write_log_fun.(deployment, seed, preamble ++ [ 118 132 "FATAL: missing activator executable sower-activator; deployment cannot continue" 119 133 ]) 120 134 ··· 124 138 125 139 result 126 140 141 + {:ok, {:error, :failed_to_realize, %SeedDeployment{seed: seed} = _seed_deploy}} -> 142 + write_log_fun.(deployment, seed, [ 143 + decision_line("realization failed for #{seed.name} (#{seed.seed_type})") 144 + ]) 145 + 146 + {:error, :failed_to_realize, seed} 147 + 127 148 {:ok, {:error, _, _} = error} -> 128 149 error 129 150 ··· 243 264 maybe_reboot(deployment, result, []) 244 265 end 245 266 246 - def maybe_reboot(%Deployment{} = _deployment, result, _opts) when result != :success do 267 + def maybe_reboot(%Deployment{} = deployment, result, opts) when result != :success do 247 268 Logger.debug(msg: "Skipping reboot due to unsuccesful deployment", result: result) 269 + write_reboot_decision(deployment, opts, "reboot skipped: deployment result was #{result}") 248 270 :ok 249 271 end 250 272 ··· 260 282 if Enum.any?(deployment.seed_deployments, &(get_in(&1.seed.seed_type) == "nixos")) do 261 283 case reboot_reason_fun.(deployment.seed_deployments) do 262 284 nil -> 285 + write_reboot_decision(deployment, opts, "no reboot required") 263 286 :ok 264 287 265 288 reason -> ··· 269 292 deployment_sid: deployment.sid, 270 293 reason: reason 271 294 ) 295 + 296 + write_reboot_decision(deployment, opts, "reboot initiated: #{reason}") 272 297 273 298 case reboot_fun.(reason: reason) do 274 299 {:ok, output} -> ··· 310 335 deployment_sid: deployment.sid 311 336 ) 312 337 338 + write_reboot_decision(deployment, opts, "reboot evaluation skipped: no NixOS seeds") 313 339 :ok 314 340 end 315 341 end 316 342 343 + defp write_reboot_decision(%Deployment{} = deployment, opts, message) do 344 + write_log_fun = Keyword.get(opts, :write_log_fun, &maybe_write_log/3) 345 + 346 + last_seed = 347 + deployment.seed_deployments 348 + |> Enum.map(& &1.seed) 349 + |> List.last() 350 + 351 + if last_seed do 352 + write_log_fun.(deployment, last_seed, [decision_line(message)]) 353 + end 354 + end 355 + 317 356 def reboot_reason( 318 357 seed_deployments, 319 358 get_profile \\ &get_deployment_profile/1, ··· 461 500 ) 462 501 end 463 502 end 503 + 504 + def decision_line(message), do: "[sower] #{message}" 464 505 465 506 defp strip_ansi(text) do 466 507 Regex.replace(~r/\x1b\[[0-9;]*[a-zA-Z]/, text, "")
+251 -3
apps/sower_agent/test/sower_agent/deployer_test.exs
··· 137 137 send(self(), :reboot_called) 138 138 {:ok, []} 139 139 end, 140 - activation_enabled_fun: fn -> true end 140 + activation_enabled_fun: fn -> true end, 141 + write_log_fun: fn _, _, _ -> :ok end 141 142 ) == :ok 142 143 143 144 refute_received :reboot_reason_called ··· 153 154 nil 154 155 end, 155 156 reboot_fun: fn _ -> flunk("reboot should not be requested") end, 156 - activation_enabled_fun: fn -> true end 157 + activation_enabled_fun: fn -> true end, 158 + write_log_fun: fn _, _, _ -> :ok end 157 159 ) == :ok 158 160 159 161 assert_received :reboot_reason_called ··· 171 173 send(self(), {:reboot_called, opts}) 172 174 {:ok, ["ok"]} 173 175 end, 174 - activation_enabled_fun: fn -> true end 176 + activation_enabled_fun: fn -> true end, 177 + write_log_fun: fn _, _, _ -> :ok end 175 178 ) == :ok 176 179 177 180 assert_received {:reboot_called, [reason: "policy_always"]} ··· 356 359 357 360 assert logs =~ 358 361 "FATAL: missing activator executable sower-activator; deployment cannot continue" 362 + end 363 + end 364 + 365 + describe "decision_line/1" do 366 + test "formats message with [sower] prefix" do 367 + assert Deployer.decision_line("reboot triggered") == "[sower] reboot triggered" 368 + end 369 + end 370 + 371 + describe "deploy log decision lines" do 372 + test "includes realization success decision line in log output" do 373 + deployment = %Deployment{ 374 + sid: "dep_real_ok", 375 + seed_deployments: [seed_deploy_with_identity("seed_r1")] 376 + } 377 + 378 + logged_lines = capture_log_lines(deployment) 379 + 380 + assert Enum.any?(logged_lines, &(&1 =~ "[sower]" and &1 =~ "realized" and &1 =~ "seed-seed_r1")) 381 + end 382 + 383 + test "includes realization failure decision line in log output" do 384 + deployment = %Deployment{ 385 + sid: "dep_real_fail", 386 + seed_deployments: [seed_deploy_with_identity("seed_rf1")] 387 + } 388 + 389 + logged_lines = 390 + capture_log_lines(deployment, 391 + realize_seed_fun: fn seed_deploy -> {:error, :failed_to_realize, seed_deploy} end 392 + ) 393 + 394 + assert Enum.any?(logged_lines, &(&1 =~ "[sower]" and &1 =~ "realization failed")) 395 + end 396 + 397 + test "includes activation mode decision line in log output" do 398 + deployment = %Deployment{ 399 + sid: "dep_mode", 400 + seed_deployments: [seed_deploy_with_identity("seed_m1")] 401 + } 402 + 403 + logged_lines = 404 + capture_log_lines(deployment, 405 + get_deployment_profile_fun: fn _ -> 406 + %DeploymentProfile{activation_args: ["boot"]} 407 + end 408 + ) 409 + 410 + assert Enum.any?(logged_lines, &(&1 =~ "[sower]" and &1 =~ "boot" and &1 =~ "seed-seed_m1")) 411 + end 412 + 413 + test "includes reboot triggered decision line" do 414 + deployment = %Deployment{ 415 + sid: "dep_reboot_log", 416 + seed_deployments: [seed_deploy_with_identity("seed_rb1")] 417 + } 418 + 419 + test_pid = self() 420 + 421 + capture_log(fn -> 422 + Deployer.run_with_opts(deployment, 423 + upgrade_opts: [ 424 + async_stream_fun: fn enumerable, func -> 425 + Enum.map(enumerable, fn item -> {:ok, func.(item)} end) 426 + end, 427 + realize_seed_fun: fn sd -> {:ok, sd} end, 428 + get_deployment_profile_fun: fn _ -> 429 + %DeploymentProfile{reboot_policy: "always"} 430 + end, 431 + activate_seed_fun: fn _seed, _profile -> {:ok, ["ok"]} end, 432 + write_log_fun: fn _deployment, _seed, output_lines -> 433 + send(test_pid, {:log_lines, output_lines}) 434 + end 435 + ], 436 + reboot_opts: [ 437 + reboot_reason_fun: fn _ -> "policy_always" end, 438 + reboot_fun: fn _opts -> {:ok, ["rebooting"]} end, 439 + activation_enabled_fun: fn -> true end 440 + ] 441 + ) 442 + end) 443 + 444 + # Collect all messages 445 + lines = collect_log_lines() 446 + all_lines = List.flatten(lines) 447 + 448 + assert Enum.any?(all_lines, &(&1 =~ "[sower]" and &1 =~ "reboot" and &1 =~ "policy_always")) 449 + end 450 + 451 + test "includes reboot skipped decision line for failed deployment" do 452 + deployment = %Deployment{ 453 + sid: "dep_reboot_skip", 454 + seed_deployments: [seed_deploy_with_identity("seed_rs1")] 455 + } 456 + 457 + test_pid = self() 458 + 459 + capture_log(fn -> 460 + Deployer.run_with_opts(deployment, 461 + upgrade_opts: [ 462 + async_stream_fun: fn enumerable, func -> 463 + Enum.map(enumerable, fn item -> {:ok, func.(item)} end) 464 + end, 465 + realize_seed_fun: fn sd -> {:ok, sd} end, 466 + get_deployment_profile_fun: fn _ -> %DeploymentProfile{} end, 467 + activate_seed_fun: fn _seed, _profile -> {:error, 1, ["failed"]} end, 468 + write_log_fun: fn _deployment, _seed, output_lines -> 469 + send(test_pid, {:log_lines, output_lines}) 470 + end 471 + ], 472 + reboot_opts: [] 473 + ) 474 + end) 475 + 476 + lines = collect_log_lines() 477 + all_lines = List.flatten(lines) 478 + 479 + assert Enum.any?(all_lines, &(&1 =~ "[sower]" and &1 =~ "reboot" and &1 =~ "skipped")) 480 + end 481 + 482 + test "includes reboot skipped decision line for non-nixos deployment" do 483 + deployment = %Deployment{ 484 + sid: "dep_reboot_nonnix", 485 + seed_deployments: [ 486 + %SeedDeployment{ 487 + subscription_sid: "sub_nonnix", 488 + seed: %Seed{ 489 + sid: "seed_nonnix", 490 + name: "my-service", 491 + seed_type: "service", 492 + artifact: "/nix/store/nonnix" 493 + } 494 + } 495 + ] 496 + } 497 + 498 + test_pid = self() 499 + 500 + capture_log(fn -> 501 + Deployer.run_with_opts(deployment, 502 + upgrade_opts: [ 503 + async_stream_fun: fn enumerable, func -> 504 + Enum.map(enumerable, fn item -> {:ok, func.(item)} end) 505 + end, 506 + realize_seed_fun: fn sd -> {:ok, sd} end, 507 + get_deployment_profile_fun: fn _ -> %DeploymentProfile{} end, 508 + activate_seed_fun: fn _seed, _profile -> {:ok, ["ok"]} end, 509 + write_log_fun: fn _deployment, _seed, output_lines -> 510 + send(test_pid, {:log_lines, output_lines}) 511 + end 512 + ], 513 + reboot_opts: [] 514 + ) 515 + end) 516 + 517 + lines = collect_log_lines() 518 + all_lines = List.flatten(lines) 519 + 520 + assert Enum.any?(all_lines, &(&1 =~ "[sower]" and &1 =~ "no NixOS seeds")) 521 + end 522 + 523 + test "includes no reboot needed decision line" do 524 + deployment = %Deployment{ 525 + sid: "dep_reboot_none", 526 + seed_deployments: [seed_deploy_with_identity("seed_rn1")] 527 + } 528 + 529 + test_pid = self() 530 + 531 + capture_log(fn -> 532 + Deployer.run_with_opts(deployment, 533 + upgrade_opts: [ 534 + async_stream_fun: fn enumerable, func -> 535 + Enum.map(enumerable, fn item -> {:ok, func.(item)} end) 536 + end, 537 + realize_seed_fun: fn sd -> {:ok, sd} end, 538 + get_deployment_profile_fun: fn _ -> %DeploymentProfile{} end, 539 + activate_seed_fun: fn _seed, _profile -> {:ok, ["ok"]} end, 540 + write_log_fun: fn _deployment, _seed, output_lines -> 541 + send(test_pid, {:log_lines, output_lines}) 542 + end 543 + ], 544 + reboot_opts: [ 545 + reboot_reason_fun: fn _ -> nil end, 546 + reboot_fun: fn _opts -> flunk("should not reboot") end, 547 + activation_enabled_fun: fn -> true end 548 + ] 549 + ) 550 + end) 551 + 552 + lines = collect_log_lines() 553 + all_lines = List.flatten(lines) 554 + 555 + assert Enum.any?(all_lines, &(&1 =~ "[sower]" and &1 =~ "no reboot required")) 556 + end 557 + 558 + test "includes default activation mode when none configured" do 559 + deployment = %Deployment{ 560 + sid: "dep_mode_default", 561 + seed_deployments: [seed_deploy_with_identity("seed_md1")] 562 + } 563 + 564 + logged_lines = capture_log_lines(deployment) 565 + 566 + assert Enum.any?(logged_lines, &(&1 =~ "[sower]" and &1 =~ "switch" and &1 =~ "seed-seed_md1")) 567 + end 568 + end 569 + 570 + defp capture_log_lines(%Deployment{} = deployment, opts \\ []) do 571 + test_pid = self() 572 + 573 + capture_log(fn -> 574 + Deployer.upgrade(deployment, 575 + async_stream_fun: fn enumerable, func -> 576 + Enum.map(enumerable, fn item -> {:ok, func.(item)} end) 577 + end, 578 + realize_seed_fun: Keyword.get(opts, :realize_seed_fun, fn sd -> {:ok, sd} end), 579 + get_deployment_profile_fun: 580 + Keyword.get(opts, :get_deployment_profile_fun, fn _ -> %DeploymentProfile{} end), 581 + activate_seed_fun: 582 + Keyword.get(opts, :activate_seed_fun, fn _seed, _profile -> 583 + {:ok, ["activation output"]} 584 + end), 585 + write_log_fun: fn _deployment, _seed, output_lines -> 586 + send(test_pid, {:log_lines, output_lines}) 587 + end 588 + ) 589 + end) 590 + 591 + receive do 592 + {:log_lines, lines} -> lines 593 + after 594 + 1000 -> [] 595 + end 596 + end 597 + 598 + defp collect_log_lines do 599 + collect_log_lines([]) 600 + end 601 + 602 + defp collect_log_lines(acc) do 603 + receive do 604 + {:log_lines, lines} -> collect_log_lines([lines | acc]) 605 + after 606 + 100 -> Enum.reverse(acc) 359 607 end 360 608 end 361 609