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