github.com/rigado/snapd@v2.42.5-go-mod+incompatible/overlord/hookstate/hookstate_test.go (about) 1 // -*- Mode: Go; indent-tabs-mode: t -*- 2 3 /* 4 * Copyright (C) 2016 Canonical Ltd 5 * 6 * This program is free software: you can redistribute it and/or modify 7 * it under the terms of the GNU General Public License version 3 as 8 * published by the Free Software Foundation. 9 * 10 * This program is distributed in the hope that it will be useful, 11 * but WITHOUT ANY WARRANTY; without even the implied warranty of 12 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the 13 * GNU General Public License for more details. 14 * 15 * You should have received a copy of the GNU General Public License 16 * along with this program. If not, see <http://www.gnu.org/licenses/>. 17 * 18 */ 19 20 package hookstate_test 21 22 import ( 23 "encoding/json" 24 "fmt" 25 "os" 26 "path/filepath" 27 "regexp" 28 "sync/atomic" 29 "testing" 30 "time" 31 32 . "gopkg.in/check.v1" 33 34 "github.com/snapcore/snapd/dirs" 35 "github.com/snapcore/snapd/overlord" 36 "github.com/snapcore/snapd/overlord/configstate/config" 37 "github.com/snapcore/snapd/overlord/hookstate" 38 "github.com/snapcore/snapd/overlord/hookstate/hooktest" 39 "github.com/snapcore/snapd/overlord/snapstate" 40 "github.com/snapcore/snapd/overlord/state" 41 "github.com/snapcore/snapd/snap" 42 "github.com/snapcore/snapd/snap/snaptest" 43 "github.com/snapcore/snapd/testutil" 44 ) 45 46 func TestHookManager(t *testing.T) { TestingT(t) } 47 48 type baseHookManagerSuite struct { 49 testutil.BaseTest 50 51 o *overlord.Overlord 52 state *state.State 53 se *overlord.StateEngine 54 manager *hookstate.HookManager 55 context *hookstate.Context 56 mockHandler *hooktest.MockHandler 57 task *state.Task 58 change *state.Change 59 command *testutil.MockCmd 60 } 61 62 func (s *baseHookManagerSuite) commonSetUpTest(c *C) { 63 s.BaseTest.SetUpTest(c) 64 65 hooktype1 := snap.NewHookType(regexp.MustCompile("^do-something$")) 66 hooktype2 := snap.NewHookType(regexp.MustCompile("^undo-something$")) 67 s.AddCleanup(snap.MockAppendSupportedHookTypes([]*snap.HookType{hooktype1, hooktype2})) 68 69 dirs.SetRootDir(c.MkDir()) 70 s.o = overlord.Mock() 71 s.state = s.o.State() 72 manager, err := hookstate.Manager(s.state, s.o.TaskRunner()) 73 c.Assert(err, IsNil) 74 s.manager = manager 75 s.se = s.o.StateEngine() 76 s.o.AddManager(s.manager) 77 s.o.AddManager(s.o.TaskRunner()) 78 c.Assert(s.o.StartUp(), IsNil) 79 80 s.AddCleanup(snap.MockSanitizePlugsSlots(func(snapInfo *snap.Info) {})) 81 82 s.command = testutil.MockCommand(c, "snap", "") 83 s.AddCleanup(s.command.Restore) 84 85 s.context = nil 86 s.mockHandler = hooktest.NewMockHandler() 87 s.manager.Register(regexp.MustCompile("configure"), func(context *hookstate.Context) hookstate.Handler { 88 s.context = context 89 return s.mockHandler 90 }) 91 s.AddCleanup(hookstate.MockErrtrackerReport(func(string, string, string, map[string]string) (string, error) { 92 return "", nil 93 })) 94 } 95 96 func (s *baseHookManagerSuite) commonTearDownTest(c *C) { 97 s.BaseTest.TearDownTest(c) 98 99 s.manager.StopHooks() 100 s.se.Stop() 101 dirs.SetRootDir("") 102 } 103 104 func (s *baseHookManagerSuite) setUpSnap(c *C, instanceName string, yaml string) { 105 hooksup := &hookstate.HookSetup{ 106 Snap: instanceName, 107 Hook: "configure", 108 Revision: snap.R(1), 109 } 110 111 initialContext := map[string]interface{}{ 112 "test-key": "test-value", 113 } 114 115 s.state.Lock() 116 defer s.state.Unlock() 117 s.task = hookstate.HookTask(s.state, "test summary", hooksup, initialContext) 118 c.Assert(s.task, NotNil, Commentf("Expected HookTask to return a task")) 119 120 s.change = s.state.NewChange("kind", "summary") 121 s.change.AddTask(s.task) 122 123 snapName, instanceKey := snap.SplitInstanceName(instanceName) 124 125 sideInfo := &snap.SideInfo{RealName: snapName, SnapID: "some-snap-id", Revision: snap.R(1)} 126 snaptest.MockSnapInstance(c, instanceName, yaml, sideInfo) 127 snapstate.Set(s.state, instanceName, &snapstate.SnapState{ 128 Active: true, 129 Sequence: []*snap.SideInfo{sideInfo}, 130 Current: snap.R(1), 131 InstanceKey: instanceKey, 132 }) 133 } 134 135 type hookManagerSuite struct { 136 baseHookManagerSuite 137 } 138 139 var _ = Suite(&hookManagerSuite{}) 140 141 var snapYaml = ` 142 name: test-snap 143 version: 1.0 144 hooks: 145 configure: 146 prepare-device: 147 do-something: 148 undo-something: 149 ` 150 151 var snapYaml1 = ` 152 name: test-snap-1 153 version: 1.0 154 hooks: 155 prepare-device: 156 ` 157 158 var snapYaml2 = ` 159 name: test-snap-2 160 version: 1.0 161 hooks: 162 prepare-device: 163 ` 164 165 func (s *hookManagerSuite) SetUpTest(c *C) { 166 s.commonSetUpTest(c) 167 168 s.setUpSnap(c, "test-snap", snapYaml) 169 } 170 171 func (s *hookManagerSuite) TearDownTest(c *C) { 172 s.commonTearDownTest(c) 173 } 174 175 func (s *hookManagerSuite) settle(c *C) { 176 err := s.o.Settle(5 * time.Second) 177 c.Assert(err, IsNil) 178 } 179 180 func (s *hookManagerSuite) TestSmoke(c *C) { 181 s.se.Ensure() 182 s.se.Wait() 183 } 184 185 func (s *hookManagerSuite) TestHookSetupJsonMarshal(c *C) { 186 hookSetup := &hookstate.HookSetup{Snap: "snap-name", Revision: snap.R(1), Hook: "hook-name"} 187 out, err := json.Marshal(hookSetup) 188 c.Assert(err, IsNil) 189 c.Check(string(out), Equals, "{\"snap\":\"snap-name\",\"revision\":\"1\",\"hook\":\"hook-name\"}") 190 } 191 192 func (s *hookManagerSuite) TestHookSetupJsonUnmarshal(c *C) { 193 out, err := json.Marshal(hookstate.HookSetup{Snap: "snap-name", Revision: snap.R(1), Hook: "hook-name"}) 194 c.Assert(err, IsNil) 195 196 var setup hookstate.HookSetup 197 err = json.Unmarshal(out, &setup) 198 c.Assert(err, IsNil) 199 c.Check(setup.Snap, Equals, "snap-name") 200 c.Check(setup.Revision, Equals, snap.R(1)) 201 c.Check(setup.Hook, Equals, "hook-name") 202 } 203 204 func (s *hookManagerSuite) TestHookTask(c *C) { 205 s.state.Lock() 206 defer s.state.Unlock() 207 208 hooksup := &hookstate.HookSetup{ 209 Snap: "test-snap", 210 Hook: "configure", 211 Revision: snap.R(1), 212 } 213 214 task := hookstate.HookTask(s.state, "test summary", hooksup, nil) 215 c.Check(task.Kind(), Equals, "run-hook") 216 217 var setup hookstate.HookSetup 218 err := task.Get("hook-setup", &setup) 219 c.Check(err, IsNil) 220 c.Check(setup.Snap, Equals, "test-snap") 221 c.Check(setup.Revision, Equals, snap.R(1)) 222 c.Check(setup.Hook, Equals, "configure") 223 } 224 225 func (s *hookManagerSuite) TestHookTaskEnsure(c *C) { 226 didRun := make(chan bool) 227 s.mockHandler.BeforeCallback = func() { 228 c.Check(s.manager.NumRunningHooks(), Equals, 1) 229 go func() { 230 didRun <- s.manager.GracefullyWaitRunningHooks() 231 }() 232 } 233 s.se.Ensure() 234 select { 235 case ok := <-didRun: 236 c.Check(ok, Equals, true) 237 case <-time.After(5 * time.Second): 238 c.Fatal("hook run should have been done by now") 239 } 240 s.se.Wait() 241 242 s.state.Lock() 243 defer s.state.Unlock() 244 245 c.Assert(s.context, NotNil, Commentf("Expected handler generator to be called with a valid context")) 246 c.Check(s.context.InstanceName(), Equals, "test-snap") 247 c.Check(s.context.SnapRevision(), Equals, snap.R(1)) 248 c.Check(s.context.HookName(), Equals, "configure") 249 250 c.Check(s.command.Calls(), DeepEquals, [][]string{{ 251 "snap", "run", "--hook", "configure", "-r", "1", "test-snap", 252 }}) 253 254 c.Check(s.mockHandler.BeforeCalled, Equals, true) 255 c.Check(s.mockHandler.DoneCalled, Equals, true) 256 c.Check(s.mockHandler.ErrorCalled, Equals, false) 257 258 c.Check(s.task.Kind(), Equals, "run-hook") 259 c.Check(s.task.Status(), Equals, state.DoneStatus) 260 c.Check(s.change.Status(), Equals, state.DoneStatus) 261 262 c.Check(s.manager.NumRunningHooks(), Equals, 0) 263 } 264 265 func (s *hookManagerSuite) TestHookTaskEnsureRestarting(c *C) { 266 // we do no start new hooks runs if we are restarting 267 s.state.RequestRestart(state.RestartDaemon) 268 269 s.se.Ensure() 270 s.se.Wait() 271 272 s.state.Lock() 273 defer s.state.Unlock() 274 275 c.Assert(s.context, IsNil) 276 277 c.Check(s.command.Calls(), HasLen, 0) 278 279 c.Check(s.mockHandler.BeforeCalled, Equals, false) 280 c.Check(s.mockHandler.DoneCalled, Equals, false) 281 c.Check(s.mockHandler.ErrorCalled, Equals, false) 282 283 c.Check(s.task.Status(), Equals, state.DoingStatus) 284 c.Check(s.change.Status(), Equals, state.DoingStatus) 285 286 c.Check(s.manager.NumRunningHooks(), Equals, 0) 287 } 288 289 func (s *hookManagerSuite) TestHookSnapMissing(c *C) { 290 s.state.Lock() 291 snapstate.Set(s.state, "test-snap", nil) 292 s.state.Unlock() 293 294 s.se.Ensure() 295 s.se.Wait() 296 297 s.state.Lock() 298 defer s.state.Unlock() 299 300 c.Check(s.change.Err(), ErrorMatches, `(?s).*cannot find "test-snap" snap.*`) 301 } 302 303 func (s *hookManagerSuite) TestHookHijackingHappy(c *C) { 304 // this works even if test-snap is not present 305 s.state.Lock() 306 snapstate.Set(s.state, "test-snap", nil) 307 s.state.Unlock() 308 309 var hijackedContext *hookstate.Context 310 s.manager.RegisterHijack("configure", "test-snap", func(ctx *hookstate.Context) error { 311 hijackedContext = ctx 312 return nil 313 }) 314 315 s.se.Ensure() 316 s.se.Wait() 317 318 s.state.Lock() 319 defer s.state.Unlock() 320 321 c.Check(hijackedContext, DeepEquals, s.context) 322 c.Check(s.command.Calls(), HasLen, 0) 323 324 c.Assert(s.context, NotNil) 325 c.Check(s.context.InstanceName(), Equals, "test-snap") 326 c.Check(s.context.SnapRevision(), Equals, snap.R(1)) 327 c.Check(s.context.HookName(), Equals, "configure") 328 329 c.Check(s.mockHandler.BeforeCalled, Equals, true) 330 c.Check(s.mockHandler.DoneCalled, Equals, true) 331 c.Check(s.mockHandler.ErrorCalled, Equals, false) 332 333 c.Check(s.task.Kind(), Equals, "run-hook") 334 c.Check(s.task.Status(), Equals, state.DoneStatus) 335 c.Check(s.change.Status(), Equals, state.DoneStatus) 336 } 337 338 func (s *hookManagerSuite) TestHookHijackingUnHappy(c *C) { 339 s.manager.RegisterHijack("configure", "test-snap", func(ctx *hookstate.Context) error { 340 return fmt.Errorf("not-happy-at-all") 341 }) 342 343 s.se.Ensure() 344 s.se.Wait() 345 346 s.state.Lock() 347 defer s.state.Unlock() 348 349 c.Check(s.command.Calls(), HasLen, 0) 350 351 c.Assert(s.context, NotNil) 352 c.Check(s.context.InstanceName(), Equals, "test-snap") 353 c.Check(s.context.SnapRevision(), Equals, snap.R(1)) 354 c.Check(s.context.HookName(), Equals, "configure") 355 356 c.Check(s.mockHandler.BeforeCalled, Equals, true) 357 c.Check(s.mockHandler.DoneCalled, Equals, false) 358 c.Check(s.mockHandler.ErrorCalled, Equals, true) 359 360 c.Check(s.task.Kind(), Equals, "run-hook") 361 c.Check(s.task.Status(), Equals, state.ErrorStatus) 362 c.Check(s.change.Status(), Equals, state.ErrorStatus) 363 } 364 365 func (s *hookManagerSuite) TestHookHijackingVeryUnHappy(c *C) { 366 f := func(ctx *hookstate.Context) error { 367 return nil 368 } 369 s.manager.RegisterHijack("configure", "test-snap", f) 370 c.Check(func() { s.manager.RegisterHijack("configure", "test-snap", f) }, PanicMatches, "hook configure for snap test-snap already hijacked") 371 } 372 373 func (s *hookManagerSuite) TestHookTaskInitializesContext(c *C) { 374 s.se.Ensure() 375 s.se.Wait() 376 377 var value string 378 c.Assert(s.context, NotNil, Commentf("Expected handler generator to be called with a valid context")) 379 s.context.Lock() 380 defer s.context.Unlock() 381 c.Check(s.context.Get("test-key", &value), IsNil, Commentf("Expected context to be initialized")) 382 c.Check(value, Equals, "test-value") 383 } 384 385 func (s *hookManagerSuite) TestHookTaskHandlesHookError(c *C) { 386 // Force the snap command to exit 1, and print something to stderr 387 cmd := testutil.MockCommand( 388 c, "snap", ">&2 echo 'hook failed at user request'; exit 1") 389 defer cmd.Restore() 390 391 s.se.Ensure() 392 s.se.Wait() 393 394 s.state.Lock() 395 defer s.state.Unlock() 396 397 c.Check(s.mockHandler.BeforeCalled, Equals, true) 398 c.Check(s.mockHandler.DoneCalled, Equals, false) 399 c.Check(s.mockHandler.ErrorCalled, Equals, true) 400 401 c.Check(s.task.Kind(), Equals, "run-hook") 402 c.Check(s.task.Status(), Equals, state.ErrorStatus) 403 c.Check(s.change.Status(), Equals, state.ErrorStatus) 404 checkTaskLogContains(c, s.task, ".*failed at user request.*") 405 406 c.Check(s.manager.NumRunningHooks(), Equals, 0) 407 } 408 409 func (s *hookManagerSuite) TestHookTaskHandleIgnoreErrorWorks(c *C) { 410 s.state.Lock() 411 var hooksup hookstate.HookSetup 412 s.task.Get("hook-setup", &hooksup) 413 hooksup.IgnoreError = true 414 s.task.Set("hook-setup", &hooksup) 415 s.state.Unlock() 416 417 // Force the snap command to exit 1, and print something to stderr 418 cmd := testutil.MockCommand( 419 c, "snap", ">&2 echo 'hook failed at user request'; exit 1") 420 defer cmd.Restore() 421 422 s.se.Ensure() 423 s.se.Wait() 424 425 s.state.Lock() 426 defer s.state.Unlock() 427 428 c.Check(s.mockHandler.BeforeCalled, Equals, true) 429 c.Check(s.mockHandler.DoneCalled, Equals, true) 430 c.Check(s.mockHandler.ErrorCalled, Equals, false) 431 432 c.Check(s.task.Kind(), Equals, "run-hook") 433 c.Check(s.task.Status(), Equals, state.DoneStatus) 434 c.Check(s.change.Status(), Equals, state.DoneStatus) 435 checkTaskLogContains(c, s.task, ".*ignoring failure in hook.*") 436 } 437 438 func (s *hookManagerSuite) TestHookTaskEnforcesTimeout(c *C) { 439 var hooksup hookstate.HookSetup 440 441 s.state.Lock() 442 s.task.Get("hook-setup", &hooksup) 443 hooksup.Timeout = time.Duration(200 * time.Millisecond) 444 s.task.Set("hook-setup", &hooksup) 445 s.state.Unlock() 446 447 // Force the snap command to hang 448 cmd := testutil.MockCommand(c, "snap", "while true; do sleep 1; done") 449 defer cmd.Restore() 450 451 s.se.Ensure() 452 s.se.Wait() 453 454 s.state.Lock() 455 defer s.state.Unlock() 456 457 c.Check(s.mockHandler.BeforeCalled, Equals, true) 458 c.Check(s.mockHandler.DoneCalled, Equals, false) 459 c.Check(s.mockHandler.ErrorCalled, Equals, true) 460 c.Check(s.mockHandler.Err, ErrorMatches, `.*exceeded maximum runtime of 200ms.*`) 461 462 c.Check(s.task.Kind(), Equals, "run-hook") 463 c.Check(s.task.Status(), Equals, state.ErrorStatus) 464 c.Check(s.change.Status(), Equals, state.ErrorStatus) 465 checkTaskLogContains(c, s.task, `.*exceeded maximum runtime of 200ms`) 466 } 467 468 func (s *hookManagerSuite) TestHookTaskEnforcesDefaultTimeout(c *C) { 469 restore := hookstate.MockDefaultHookTimeout(150 * time.Millisecond) 470 defer restore() 471 472 // Force the snap command to hang 473 cmd := testutil.MockCommand(c, "snap", "while true; do sleep 1; done") 474 defer cmd.Restore() 475 476 s.se.Ensure() 477 s.se.Wait() 478 479 s.state.Lock() 480 defer s.state.Unlock() 481 482 c.Check(s.mockHandler.BeforeCalled, Equals, true) 483 c.Check(s.mockHandler.DoneCalled, Equals, false) 484 c.Check(s.mockHandler.ErrorCalled, Equals, true) 485 c.Check(s.mockHandler.Err, ErrorMatches, `.*exceeded maximum runtime of 150ms.*`) 486 487 c.Check(s.task.Kind(), Equals, "run-hook") 488 c.Check(s.task.Status(), Equals, state.ErrorStatus) 489 c.Check(s.change.Status(), Equals, state.ErrorStatus) 490 checkTaskLogContains(c, s.task, `.*exceeded maximum runtime of 150ms`) 491 } 492 493 func (s *hookManagerSuite) TestHookTaskEnforcedTimeoutWithIgnoreError(c *C) { 494 var hooksup hookstate.HookSetup 495 496 s.state.Lock() 497 s.task.Get("hook-setup", &hooksup) 498 hooksup.Timeout = time.Duration(200 * time.Millisecond) 499 hooksup.IgnoreError = true 500 s.task.Set("hook-setup", &hooksup) 501 s.state.Unlock() 502 503 // Force the snap command to hang 504 cmd := testutil.MockCommand(c, "snap", "while true; do sleep 1; done") 505 defer cmd.Restore() 506 507 s.se.Ensure() 508 s.se.Wait() 509 510 s.state.Lock() 511 defer s.state.Unlock() 512 513 c.Check(s.mockHandler.BeforeCalled, Equals, true) 514 c.Check(s.mockHandler.DoneCalled, Equals, true) 515 c.Check(s.mockHandler.ErrorCalled, Equals, false) 516 c.Check(s.mockHandler.Err, IsNil) 517 518 c.Check(s.task.Kind(), Equals, "run-hook") 519 c.Check(s.task.Status(), Equals, state.DoneStatus) 520 c.Check(s.change.Status(), Equals, state.DoneStatus) 521 checkTaskLogContains(c, s.task, `.*ignoring failure in hook.*exceeded maximum runtime of 200ms`) 522 } 523 524 func (s *hookManagerSuite) TestHookTaskCanKillHook(c *C) { 525 // Force the snap command to hang 526 cmd := testutil.MockCommand(c, "snap", "while true; do sleep 1; done") 527 defer cmd.Restore() 528 529 s.se.Ensure() 530 531 // Abort the change, which should kill the hanging hook, and 532 // wait for the task to complete. 533 s.state.Lock() 534 s.change.Abort() 535 s.state.Unlock() 536 s.se.Ensure() 537 s.se.Wait() 538 539 s.state.Lock() 540 defer s.state.Unlock() 541 542 c.Check(s.mockHandler.BeforeCalled, Equals, true) 543 c.Check(s.mockHandler.DoneCalled, Equals, false) 544 c.Check(s.mockHandler.ErrorCalled, Equals, true) 545 c.Check(s.mockHandler.Err, ErrorMatches, "<aborted>") 546 547 c.Check(s.task.Kind(), Equals, "run-hook") 548 c.Check(s.task.Status(), Equals, state.ErrorStatus) 549 c.Check(s.change.Status(), Equals, state.ErrorStatus) 550 checkTaskLogContains(c, s.task, `run hook "[^"]*": <aborted>`) 551 552 c.Check(s.manager.NumRunningHooks(), Equals, 0) 553 } 554 555 func (s *hookManagerSuite) TestHookTaskCorrectlyIncludesContext(c *C) { 556 // Force the snap command to exit with a failure and print to stderr so we 557 // can catch and verify it. 558 cmd := testutil.MockCommand( 559 c, "snap", ">&2 echo \"SNAP_COOKIE=$SNAP_COOKIE\"; exit 1") 560 defer cmd.Restore() 561 562 s.se.Ensure() 563 s.se.Wait() 564 565 s.state.Lock() 566 defer s.state.Unlock() 567 568 c.Check(s.mockHandler.BeforeCalled, Equals, true) 569 c.Check(s.mockHandler.DoneCalled, Equals, false) 570 c.Check(s.mockHandler.ErrorCalled, Equals, true) 571 572 c.Check(s.task.Kind(), Equals, "run-hook") 573 c.Check(s.task.Status(), Equals, state.ErrorStatus) 574 c.Check(s.change.Status(), Equals, state.ErrorStatus) 575 checkTaskLogContains(c, s.task, `.*SNAP_COOKIE=\S+`) 576 } 577 578 func (s *hookManagerSuite) TestHookTaskHandlerBeforeError(c *C) { 579 s.mockHandler.BeforeError = true 580 581 s.se.Ensure() 582 s.se.Wait() 583 584 s.state.Lock() 585 defer s.state.Unlock() 586 587 c.Check(s.mockHandler.BeforeCalled, Equals, true) 588 c.Check(s.mockHandler.DoneCalled, Equals, false) 589 c.Check(s.mockHandler.ErrorCalled, Equals, false) 590 591 c.Check(s.task.Kind(), Equals, "run-hook") 592 c.Check(s.task.Status(), Equals, state.ErrorStatus) 593 c.Check(s.change.Status(), Equals, state.ErrorStatus) 594 checkTaskLogContains(c, s.task, `.*Before failed at user request.*`) 595 } 596 597 func (s *hookManagerSuite) TestHookTaskHandlerDoneError(c *C) { 598 s.mockHandler.DoneError = true 599 600 s.se.Ensure() 601 s.se.Wait() 602 603 s.state.Lock() 604 defer s.state.Unlock() 605 606 c.Check(s.mockHandler.BeforeCalled, Equals, true) 607 c.Check(s.mockHandler.DoneCalled, Equals, true) 608 c.Check(s.mockHandler.ErrorCalled, Equals, false) 609 610 c.Check(s.task.Kind(), Equals, "run-hook") 611 c.Check(s.task.Status(), Equals, state.ErrorStatus) 612 c.Check(s.change.Status(), Equals, state.ErrorStatus) 613 checkTaskLogContains(c, s.task, `.*Done failed at user request.*`) 614 } 615 616 func (s *hookManagerSuite) TestHookTaskHandlerErrorError(c *C) { 617 s.mockHandler.ErrorError = true 618 619 // Force the snap command to simply exit 1, so the handler Error() runs 620 cmd := testutil.MockCommand(c, "snap", "exit 1") 621 defer cmd.Restore() 622 623 s.se.Ensure() 624 s.se.Wait() 625 626 s.state.Lock() 627 defer s.state.Unlock() 628 629 c.Check(s.mockHandler.BeforeCalled, Equals, true) 630 c.Check(s.mockHandler.DoneCalled, Equals, false) 631 c.Check(s.mockHandler.ErrorCalled, Equals, true) 632 633 c.Check(s.task.Kind(), Equals, "run-hook") 634 c.Check(s.task.Status(), Equals, state.ErrorStatus) 635 c.Check(s.change.Status(), Equals, state.ErrorStatus) 636 checkTaskLogContains(c, s.task, `.*Error failed at user request.*`) 637 } 638 639 func (s *hookManagerSuite) TestHookUndoRunsOnError(c *C) { 640 handler := hooktest.NewMockHandler() 641 undoHandler := hooktest.NewMockHandler() 642 643 s.manager.Register(regexp.MustCompile("^do-something$"), func(context *hookstate.Context) hookstate.Handler { 644 return handler 645 }) 646 s.manager.Register(regexp.MustCompile("^undo-something$"), func(context *hookstate.Context) hookstate.Handler { 647 return undoHandler 648 }) 649 650 hooksup := &hookstate.HookSetup{ 651 Snap: "test-snap", 652 Hook: "do-something", 653 Revision: snap.R(1), 654 } 655 undohooksup := &hookstate.HookSetup{ 656 Snap: "test-snap", 657 Hook: "undo-something", 658 Revision: snap.R(1), 659 } 660 661 // use unknown hook to fail the change 662 failinghooksup := &hookstate.HookSetup{ 663 Snap: "test-snap", 664 Hook: "unknown-hook", 665 Revision: snap.R(1), 666 } 667 668 initialContext := map[string]interface{}{} 669 670 s.state.Lock() 671 task := hookstate.HookTaskWithUndo(s.state, "test summary", hooksup, undohooksup, initialContext) 672 c.Assert(task, NotNil) 673 failtask := hookstate.HookTask(s.state, "test summary", failinghooksup, initialContext) 674 failtask.WaitFor(task) 675 676 change := s.state.NewChange("kind", "summary") 677 change.AddTask(task) 678 change.AddTask(failtask) 679 s.state.Unlock() 680 681 s.settle(c) 682 683 s.state.Lock() 684 defer s.state.Unlock() 685 686 c.Check(handler.BeforeCalled, Equals, true) 687 c.Check(handler.DoneCalled, Equals, true) 688 c.Check(handler.ErrorCalled, Equals, false) 689 690 c.Check(undoHandler.BeforeCalled, Equals, true) 691 c.Check(undoHandler.DoneCalled, Equals, true) 692 c.Check(undoHandler.ErrorCalled, Equals, false) 693 694 c.Check(task.Status(), Equals, state.UndoneStatus) 695 c.Check(change.Status(), Equals, state.ErrorStatus) 696 697 c.Check(s.manager.NumRunningHooks(), Equals, 0) 698 } 699 700 func (s *hookManagerSuite) TestHookWithoutHandlerIsError(c *C) { 701 hooksup := &hookstate.HookSetup{ 702 Snap: "test-snap", 703 Hook: "prepare-device", 704 Revision: snap.R(1), 705 } 706 s.state.Lock() 707 s.task.Set("hook-setup", hooksup) 708 s.state.Unlock() 709 710 s.se.Ensure() 711 s.se.Wait() 712 713 s.state.Lock() 714 defer s.state.Unlock() 715 716 c.Check(s.task.Kind(), Equals, "run-hook") 717 c.Check(s.task.Status(), Equals, state.ErrorStatus) 718 c.Check(s.change.Status(), Equals, state.ErrorStatus) 719 checkTaskLogContains(c, s.task, `.*no registered handlers for hook "prepare-device".*`) 720 } 721 722 func (s *hookManagerSuite) TestHookWithMultipleHandlersIsError(c *C) { 723 // Register multiple times for this hook 724 s.manager.Register(regexp.MustCompile("configure"), func(context *hookstate.Context) hookstate.Handler { 725 return hooktest.NewMockHandler() 726 }) 727 728 s.se.Ensure() 729 s.se.Wait() 730 731 s.state.Lock() 732 defer s.state.Unlock() 733 734 c.Check(s.task.Kind(), Equals, "run-hook") 735 c.Check(s.task.Status(), Equals, state.ErrorStatus) 736 c.Check(s.change.Status(), Equals, state.ErrorStatus) 737 738 checkTaskLogContains(c, s.task, `.*2 handlers registered for hook "configure".*`) 739 } 740 741 func (s *hookManagerSuite) TestHookWithoutHookIsError(c *C) { 742 hooksup := &hookstate.HookSetup{ 743 Snap: "test-snap", 744 Hook: "missing-hook", 745 } 746 s.state.Lock() 747 s.task.Set("hook-setup", hooksup) 748 s.state.Unlock() 749 750 s.se.Ensure() 751 s.se.Wait() 752 753 s.state.Lock() 754 defer s.state.Unlock() 755 756 c.Check(s.task.Kind(), Equals, "run-hook") 757 c.Check(s.task.Status(), Equals, state.ErrorStatus) 758 c.Check(s.change.Status(), Equals, state.ErrorStatus) 759 checkTaskLogContains(c, s.task, `.*snap "test-snap" has no "missing-hook" hook`) 760 } 761 762 func (s *hookManagerSuite) TestHookWithoutHookOptional(c *C) { 763 s.manager.Register(regexp.MustCompile("missing-hook"), func(context *hookstate.Context) hookstate.Handler { 764 return s.mockHandler 765 }) 766 767 hooksup := &hookstate.HookSetup{ 768 Snap: "test-snap", 769 Hook: "missing-hook", 770 Optional: true, 771 } 772 s.state.Lock() 773 s.task.Set("hook-setup", hooksup) 774 s.state.Unlock() 775 776 s.se.Ensure() 777 s.se.Wait() 778 779 c.Check(s.mockHandler.BeforeCalled, Equals, false) 780 c.Check(s.mockHandler.DoneCalled, Equals, false) 781 c.Check(s.mockHandler.ErrorCalled, Equals, false) 782 783 c.Check(s.command.Calls(), IsNil) 784 785 s.state.Lock() 786 defer s.state.Unlock() 787 788 c.Check(s.task.Kind(), Equals, "run-hook") 789 c.Check(s.task.Status(), Equals, state.DoneStatus) 790 c.Check(s.change.Status(), Equals, state.DoneStatus) 791 792 c.Logf("Task log:\n%s\n", s.task.Log()) 793 } 794 795 func (s *hookManagerSuite) TestHookWithoutHookAlways(c *C) { 796 s.manager.Register(regexp.MustCompile("missing-hook"), func(context *hookstate.Context) hookstate.Handler { 797 return s.mockHandler 798 }) 799 800 hooksup := &hookstate.HookSetup{ 801 Snap: "test-snap", 802 Hook: "missing-hook", 803 Optional: true, 804 Always: true, 805 } 806 s.state.Lock() 807 s.task.Set("hook-setup", hooksup) 808 s.state.Unlock() 809 810 s.se.Ensure() 811 s.se.Wait() 812 813 c.Check(s.mockHandler.BeforeCalled, Equals, true) 814 c.Check(s.mockHandler.DoneCalled, Equals, true) 815 c.Check(s.mockHandler.ErrorCalled, Equals, false) 816 817 c.Check(s.command.Calls(), IsNil) 818 819 s.state.Lock() 820 defer s.state.Unlock() 821 822 c.Check(s.task.Kind(), Equals, "run-hook") 823 c.Check(s.task.Status(), Equals, state.DoneStatus) 824 c.Check(s.change.Status(), Equals, state.DoneStatus) 825 826 c.Logf("Task log:\n%s\n", s.task.Log()) 827 } 828 829 func (s *hookManagerSuite) TestOptionalHookWithMissingHandler(c *C) { 830 hooksup := &hookstate.HookSetup{ 831 Snap: "test-snap", 832 Hook: "missing-hook-and-no-handler", 833 Optional: true, 834 } 835 s.state.Lock() 836 s.task.Set("hook-setup", hooksup) 837 s.state.Unlock() 838 839 s.se.Ensure() 840 s.se.Wait() 841 842 c.Check(s.command.Calls(), IsNil) 843 844 s.state.Lock() 845 defer s.state.Unlock() 846 847 c.Check(s.task.Kind(), Equals, "run-hook") 848 c.Check(s.task.Status(), Equals, state.DoneStatus) 849 c.Check(s.change.Status(), Equals, state.DoneStatus) 850 851 c.Logf("Task log:\n%s\n", s.task.Log()) 852 } 853 854 func checkTaskLogContains(c *C, task *state.Task, pattern string) { 855 exp := regexp.MustCompile(pattern) 856 found := false 857 for _, message := range task.Log() { 858 if exp.MatchString(message) { 859 found = true 860 } 861 } 862 863 c.Check(found, Equals, true, Commentf("Expected to find regex %q in task log: %v", pattern, task.Log())) 864 } 865 866 func (s *hookManagerSuite) TestHookTaskRunsRightSnapCmd(c *C) { 867 coreSnapCmdPath := filepath.Join(dirs.SnapMountDir, "core/12/usr/bin/snap") 868 err := os.MkdirAll(filepath.Dir(coreSnapCmdPath), 0755) 869 c.Assert(err, IsNil) 870 cmd := testutil.MockCommand(c, coreSnapCmdPath, "") 871 defer cmd.Restore() 872 873 r := hookstate.MockReadlink(func(p string) (string, error) { 874 c.Assert(p, Equals, "/proc/self/exe") 875 return filepath.Join(dirs.SnapMountDir, "core/12/usr/lib/snapd/snapd"), nil 876 }) 877 defer r() 878 879 s.se.Ensure() 880 s.se.Wait() 881 882 s.state.Lock() 883 defer s.state.Unlock() 884 885 c.Assert(s.context, NotNil, Commentf("Expected handler generator to be called with a valid context")) 886 c.Check(cmd.Calls(), DeepEquals, [][]string{{ 887 "snap", "run", "--hook", "configure", "-r", "1", "test-snap", 888 }}) 889 890 } 891 892 func (s *hookManagerSuite) TestHookTaskHandlerReportsErrorIfRequested(c *C) { 893 s.state.Lock() 894 var hooksup hookstate.HookSetup 895 s.task.Get("hook-setup", &hooksup) 896 hooksup.TrackError = true 897 s.task.Set("hook-setup", &hooksup) 898 s.state.Unlock() 899 900 errtrackerCalled := false 901 hookstate.MockErrtrackerReport(func(snap, errmsg, dupSig string, extra map[string]string) (string, error) { 902 c.Check(snap, Equals, "test-snap") 903 c.Check(errmsg, Equals, "hook configure in snap \"test-snap\" failed: hook failed at user request") 904 c.Check(dupSig, Equals, "hook:test-snap:configure:exit status 1\nhook failed at user request\n") 905 906 errtrackerCalled = true 907 return "some-oopsid", nil 908 }) 909 910 // Force the snap command to exit 1, and print something to stderr 911 cmd := testutil.MockCommand( 912 c, "snap", ">&2 echo 'hook failed at user request'; exit 1") 913 defer cmd.Restore() 914 915 s.se.Ensure() 916 s.se.Wait() 917 918 s.state.Lock() 919 defer s.state.Unlock() 920 921 c.Check(errtrackerCalled, Equals, true) 922 } 923 924 func (s *hookManagerSuite) TestHookTaskHandlerReportsErrorDisabled(c *C) { 925 s.state.Lock() 926 var hooksup hookstate.HookSetup 927 s.task.Get("hook-setup", &hooksup) 928 hooksup.TrackError = true 929 s.task.Set("hook-setup", &hooksup) 930 931 tr := config.NewTransaction(s.state) 932 tr.Set("core", "problem-reports.disabled", true) 933 tr.Commit() 934 s.state.Unlock() 935 936 hookstate.MockErrtrackerReport(func(snap, errmsg, dupSig string, extra map[string]string) (string, error) { 937 c.Fatalf("no error reports should be generated") 938 return "", nil 939 }) 940 941 // Force the snap command to exit 1, and print something to stderr 942 cmd := testutil.MockCommand( 943 c, "snap", ">&2 echo 'hook failed at user request'; exit 1") 944 defer cmd.Restore() 945 946 s.se.Ensure() 947 s.se.Wait() 948 949 s.state.Lock() 950 defer s.state.Unlock() 951 } 952 953 func (s *hookManagerSuite) TestHookTasksForSameSnapAreSerialized(c *C) { 954 var Executing int32 955 var TotalExecutions int32 956 957 s.mockHandler.BeforeCallback = func() { 958 executing := atomic.AddInt32(&Executing, 1) 959 if executing != 1 { 960 panic(fmt.Sprintf("More than one handler executed: %d", executing)) 961 } 962 } 963 964 s.mockHandler.DoneCallback = func() { 965 executing := atomic.AddInt32(&Executing, -1) 966 if executing != 0 { 967 panic(fmt.Sprintf("More than one handler executed: %d", executing)) 968 } 969 atomic.AddInt32(&TotalExecutions, 1) 970 } 971 972 hooksup := &hookstate.HookSetup{ 973 Snap: "test-snap", 974 Hook: "configure", 975 Revision: snap.R(1), 976 } 977 978 s.state.Lock() 979 980 var tasks []*state.Task 981 for i := 0; i < 20; i++ { 982 task := hookstate.HookTask(s.state, "test summary", hooksup, nil) 983 c.Assert(s.task, NotNil) 984 change := s.state.NewChange("kind", "summary") 985 change.AddTask(task) 986 tasks = append(tasks, task) 987 } 988 s.state.Unlock() 989 990 s.settle(c) 991 992 s.state.Lock() 993 defer s.state.Unlock() 994 995 c.Check(s.task.Kind(), Equals, "run-hook") 996 c.Check(s.task.Status(), Equals, state.DoneStatus) 997 c.Check(s.change.Status(), Equals, state.DoneStatus) 998 999 for i := 0; i < len(tasks); i++ { 1000 c.Check(tasks[i].Kind(), Equals, "run-hook") 1001 c.Check(tasks[i].Status(), Equals, state.DoneStatus) 1002 } 1003 c.Assert(atomic.LoadInt32(&TotalExecutions), Equals, int32(1+len(tasks))) 1004 c.Assert(atomic.LoadInt32(&Executing), Equals, int32(0)) 1005 } 1006 1007 type MockConcurrentHandler struct { 1008 onDone func() 1009 } 1010 1011 func (h *MockConcurrentHandler) Before() error { 1012 return nil 1013 } 1014 1015 func (h *MockConcurrentHandler) Done() error { 1016 h.onDone() 1017 return nil 1018 } 1019 1020 func (h *MockConcurrentHandler) Error(err error) error { 1021 return nil 1022 } 1023 1024 func NewMockConcurrentHandler(onDone func()) *MockConcurrentHandler { 1025 return &MockConcurrentHandler{onDone: onDone} 1026 } 1027 1028 func (s *hookManagerSuite) TestHookTasksForDifferentSnapsRunConcurrently(c *C) { 1029 hooksup1 := &hookstate.HookSetup{ 1030 Snap: "test-snap-1", 1031 Hook: "prepare-device", 1032 Revision: snap.R(1), 1033 } 1034 hooksup2 := &hookstate.HookSetup{ 1035 Snap: "test-snap-2", 1036 Hook: "prepare-device", 1037 Revision: snap.R(1), 1038 } 1039 1040 s.state.Lock() 1041 1042 sideInfo := &snap.SideInfo{RealName: "test-snap-1", SnapID: "some-snap-id1", Revision: snap.R(1)} 1043 info := snaptest.MockSnap(c, snapYaml1, sideInfo) 1044 c.Assert(info.Hooks, HasLen, 1) 1045 snapstate.Set(s.state, "test-snap-1", &snapstate.SnapState{ 1046 Active: true, 1047 Sequence: []*snap.SideInfo{sideInfo}, 1048 Current: snap.R(1), 1049 }) 1050 1051 sideInfo = &snap.SideInfo{RealName: "test-snap-2", SnapID: "some-snap-id2", Revision: snap.R(1)} 1052 snaptest.MockSnap(c, snapYaml2, sideInfo) 1053 snapstate.Set(s.state, "test-snap-2", &snapstate.SnapState{ 1054 Active: true, 1055 Sequence: []*snap.SideInfo{sideInfo}, 1056 Current: snap.R(1), 1057 }) 1058 1059 var testSnap1HookCalls, testSnap2HookCalls int 1060 ch := make(chan struct{}) 1061 mockHandler1 := NewMockConcurrentHandler(func() { 1062 ch <- struct{}{} 1063 testSnap1HookCalls++ 1064 }) 1065 mockHandler2 := NewMockConcurrentHandler(func() { 1066 <-ch 1067 testSnap2HookCalls++ 1068 }) 1069 s.manager.Register(regexp.MustCompile("prepare-device"), func(context *hookstate.Context) hookstate.Handler { 1070 if context.InstanceName() == "test-snap-1" { 1071 return mockHandler1 1072 } 1073 if context.InstanceName() == "test-snap-2" { 1074 return mockHandler2 1075 } 1076 c.Fatalf("unknown snap: %s", context.InstanceName()) 1077 return nil 1078 }) 1079 1080 task1 := hookstate.HookTask(s.state, "test summary", hooksup1, nil) 1081 c.Assert(task1, NotNil) 1082 change1 := s.state.NewChange("kind", "summary") 1083 change1.AddTask(task1) 1084 1085 task2 := hookstate.HookTask(s.state, "test summary", hooksup2, nil) 1086 c.Assert(task2, NotNil) 1087 change2 := s.state.NewChange("kind", "summary") 1088 change2.AddTask(task2) 1089 1090 s.state.Unlock() 1091 1092 s.settle(c) 1093 1094 s.state.Lock() 1095 defer s.state.Unlock() 1096 1097 c.Check(task1.Status(), Equals, state.DoneStatus) 1098 c.Check(change1.Status(), Equals, state.DoneStatus) 1099 c.Check(task2.Status(), Equals, state.DoneStatus) 1100 c.Check(change2.Status(), Equals, state.DoneStatus) 1101 c.Assert(testSnap1HookCalls, Equals, 1) 1102 c.Assert(testSnap2HookCalls, Equals, 1) 1103 } 1104 1105 func (s *hookManagerSuite) TestCompatForConfigureSnapd(c *C) { 1106 st := s.state 1107 1108 st.Lock() 1109 defer st.Unlock() 1110 1111 task := st.NewTask("configure-snapd", "Snapd between 2.29 and 2.30 in edge insertd those tasks") 1112 chg := st.NewChange("configure", "configure snapd") 1113 chg.AddTask(task) 1114 1115 st.Unlock() 1116 s.se.Ensure() 1117 s.se.Wait() 1118 st.Lock() 1119 1120 c.Check(chg.Status(), Equals, state.DoneStatus) 1121 c.Check(task.Status(), Equals, state.DoneStatus) 1122 } 1123 1124 func (s *hookManagerSuite) TestGracefullyWaitRunningHooksTimeout(c *C) { 1125 restore := hookstate.MockDefaultHookTimeout(100 * time.Millisecond) 1126 defer restore() 1127 1128 // this works even if test-snap is not present 1129 s.state.Lock() 1130 snapstate.Set(s.state, "test-snap", nil) 1131 s.state.Unlock() 1132 1133 quit := make(chan struct{}) 1134 defer func() { 1135 quit <- struct{}{} 1136 }() 1137 didRun := make(chan bool) 1138 s.mockHandler.BeforeCallback = func() { 1139 c.Check(s.manager.NumRunningHooks(), Equals, 1) 1140 go func() { 1141 didRun <- s.manager.GracefullyWaitRunningHooks() 1142 }() 1143 } 1144 1145 s.manager.RegisterHijack("configure", "test-snap", func(ctx *hookstate.Context) error { 1146 <-quit 1147 return nil 1148 }) 1149 1150 s.se.Ensure() 1151 select { 1152 case noPending := <-didRun: 1153 c.Check(noPending, Equals, false) 1154 case <-time.After(2 * time.Second): 1155 c.Fatal("timeout should have expired") 1156 } 1157 } 1158 1159 func (s *hookManagerSuite) TestSnapstateOpConflict(c *C) { 1160 s.state.Lock() 1161 defer s.state.Unlock() 1162 _, err := snapstate.Disable(s.state, "test-snap") 1163 c.Assert(err, ErrorMatches, `snap "test-snap" has "kind" change in progress`) 1164 } 1165 1166 func (s *hookManagerSuite) TestHookHijackingNoConflict(c *C) { 1167 s.state.Lock() 1168 defer s.state.Unlock() 1169 1170 s.manager.RegisterHijack("configure", "test-snap", func(ctx *hookstate.Context) error { 1171 return nil 1172 }) 1173 1174 // no conflict on hijacked hooks 1175 _, err := snapstate.Disable(s.state, "test-snap") 1176 c.Assert(err, IsNil) 1177 } 1178 1179 type parallelInstancesHookManagerSuite struct { 1180 baseHookManagerSuite 1181 } 1182 1183 var _ = Suite(¶llelInstancesHookManagerSuite{}) 1184 1185 func (s *parallelInstancesHookManagerSuite) SetUpTest(c *C) { 1186 s.commonSetUpTest(c) 1187 s.setUpSnap(c, "test-snap_instance", snapYaml) 1188 } 1189 1190 func (s *parallelInstancesHookManagerSuite) TearDownTest(c *C) { 1191 s.commonTearDownTest(c) 1192 } 1193 1194 func (s *parallelInstancesHookManagerSuite) TestHookTaskEnsureHookRan(c *C) { 1195 didRun := make(chan bool) 1196 s.mockHandler.BeforeCallback = func() { 1197 c.Check(s.manager.NumRunningHooks(), Equals, 1) 1198 go func() { 1199 didRun <- s.manager.GracefullyWaitRunningHooks() 1200 }() 1201 } 1202 s.se.Ensure() 1203 select { 1204 case ok := <-didRun: 1205 c.Check(ok, Equals, true) 1206 case <-time.After(5 * time.Second): 1207 c.Fatal("hook run should have been done by now") 1208 } 1209 s.se.Wait() 1210 1211 s.state.Lock() 1212 defer s.state.Unlock() 1213 1214 c.Check(s.context.InstanceName(), Equals, "test-snap_instance") 1215 c.Check(s.context.SnapRevision(), Equals, snap.R(1)) 1216 c.Check(s.context.HookName(), Equals, "configure") 1217 1218 c.Check(s.command.Calls(), DeepEquals, [][]string{{ 1219 "snap", "run", "--hook", "configure", "-r", "1", "test-snap_instance", 1220 }}) 1221 1222 c.Check(s.mockHandler.BeforeCalled, Equals, true) 1223 c.Check(s.mockHandler.DoneCalled, Equals, true) 1224 c.Check(s.mockHandler.ErrorCalled, Equals, false) 1225 1226 c.Check(s.task.Kind(), Equals, "run-hook") 1227 c.Check(s.task.Status(), Equals, state.DoneStatus) 1228 c.Check(s.change.Status(), Equals, state.DoneStatus) 1229 1230 c.Check(s.manager.NumRunningHooks(), Equals, 0) 1231 }