github.com/rclone/rclone@v1.66.1-0.20240517100346-7b89735ae726/vfs/vfscache/writeback/writeback_test.go (about) 1 package writeback 2 3 import ( 4 "container/heap" 5 "context" 6 "errors" 7 "fmt" 8 "strings" 9 "sync" 10 "testing" 11 "time" 12 13 "github.com/rclone/rclone/fs" 14 "github.com/rclone/rclone/vfs/vfscommon" 15 "github.com/stretchr/testify/assert" 16 ) 17 18 func newTestWriteBack(t *testing.T) (wb *WriteBack, cancel func()) { 19 ctx, cancel := context.WithCancel(context.Background()) 20 opt := vfscommon.DefaultOpt 21 opt.WriteBack = 100 * time.Millisecond 22 wb = New(ctx, &opt) 23 return wb, cancel 24 } 25 26 // string for debugging - make a copy and pop the items out in order 27 func (wb *WriteBack) string(t *testing.T) string { 28 wb.mu.Lock() 29 defer wb.mu.Unlock() 30 ws := wb.items 31 32 // check indexes OK first 33 for i := range ws { 34 assert.Equal(t, i, ws[i].index, ws[i].name) 35 } 36 wsCopy := make(writeBackItems, len(ws)) 37 // deep copy the elements 38 for i := range wsCopy { 39 item := *ws[i] 40 wsCopy[i] = &item 41 } 42 // print them 43 var out []string 44 for wsCopy.Len() > 0 { 45 out = append(out, heap.Pop(&wsCopy).(*writeBackItem).name) 46 } 47 return strings.Join(out, ",") 48 } 49 50 func TestWriteBackItems(t *testing.T) { 51 // Test the items heap behaves properly 52 now := time.Now() 53 wbItem1 := writeBackItem{name: "one", expiry: now.Add(1 * time.Second)} 54 wbItem2 := writeBackItem{name: "two", expiry: now.Add(2 * time.Second)} 55 wbItem3 := writeBackItem{name: "three", expiry: now.Add(4 * time.Second)} 56 57 wb := &WriteBack{ 58 items: writeBackItems{}, 59 } 60 61 heap.Init(&wb.items) 62 assert.Equal(t, "", wb.string(t)) 63 heap.Push(&wb.items, &wbItem2) 64 assert.Equal(t, "two", wb.string(t)) 65 heap.Push(&wb.items, &wbItem3) 66 assert.Equal(t, "two,three", wb.string(t)) 67 heap.Push(&wb.items, &wbItem1) 68 assert.Equal(t, "one,two,three", wb.string(t)) 69 70 wb.items._update(&wbItem1, now.Add(3*time.Second)) 71 assert.Equal(t, "two,one,three", wb.string(t)) 72 73 wb.items._update(&wbItem1, now.Add(5*time.Second)) 74 assert.Equal(t, "two,three,one", wb.string(t)) 75 76 // Set all times the same - should sort in insertion order 77 wb.items._update(&wbItem1, now) 78 wb.items._update(&wbItem2, now) 79 wb.items._update(&wbItem3, now) 80 assert.Equal(t, "one,two,three", wb.string(t)) 81 } 82 83 func checkOnHeap(t *testing.T, wb *WriteBack, wbItem *writeBackItem) { 84 wb.mu.Lock() 85 defer wb.mu.Unlock() 86 assert.True(t, wbItem.onHeap) 87 for i := range wb.items { 88 if wb.items[i] == wbItem { 89 return 90 } 91 } 92 assert.Failf(t, "expecting %q on heap", wbItem.name) 93 } 94 95 func checkNotOnHeap(t *testing.T, wb *WriteBack, wbItem *writeBackItem) { 96 wb.mu.Lock() 97 defer wb.mu.Unlock() 98 assert.False(t, wbItem.onHeap) 99 for i := range wb.items { 100 if wb.items[i] == wbItem { 101 t.Errorf("not expecting %q on heap", wbItem.name) 102 } 103 } 104 } 105 106 func checkInLookup(t *testing.T, wb *WriteBack, wbItem *writeBackItem) { 107 wb.mu.Lock() 108 defer wb.mu.Unlock() 109 assert.Equal(t, wbItem, wb.lookup[wbItem.id]) 110 } 111 112 func checkNotInLookup(t *testing.T, wb *WriteBack, wbItem *writeBackItem) { 113 wb.mu.Lock() 114 defer wb.mu.Unlock() 115 assert.Nil(t, wb.lookup[wbItem.id]) 116 } 117 118 func TestWriteBackItemCRUD(t *testing.T) { 119 wb, cancel := newTestWriteBack(t) 120 defer cancel() 121 122 // _peekItem empty 123 assert.Nil(t, wb._peekItem()) 124 125 wbItem1 := wb._newItem(0, "one") 126 checkOnHeap(t, wb, wbItem1) 127 checkInLookup(t, wb, wbItem1) 128 129 wbItem2 := wb._newItem(0, "two") 130 checkOnHeap(t, wb, wbItem2) 131 checkInLookup(t, wb, wbItem2) 132 133 wbItem3 := wb._newItem(0, "three") 134 checkOnHeap(t, wb, wbItem3) 135 checkInLookup(t, wb, wbItem3) 136 137 assert.Equal(t, "one,two,three", wb.string(t)) 138 139 // _delItem 140 wb._delItem(wbItem2) 141 checkOnHeap(t, wb, wbItem2) 142 checkNotInLookup(t, wb, wbItem2) 143 144 // _addItem 145 wb._addItem(wbItem2) 146 checkOnHeap(t, wb, wbItem2) 147 checkInLookup(t, wb, wbItem2) 148 149 // _popItem 150 assert.True(t, wbItem1.onHeap) 151 poppedWbItem := wb._popItem() 152 assert.Equal(t, wbItem1, poppedWbItem) 153 checkNotOnHeap(t, wb, wbItem1) 154 checkInLookup(t, wb, wbItem1) 155 assert.Equal(t, "two,three", wb.string(t)) 156 157 // _pushItem 158 wb._pushItem(wbItem1) 159 checkOnHeap(t, wb, wbItem1) 160 checkInLookup(t, wb, wbItem1) 161 assert.Equal(t, "one,two,three", wb.string(t)) 162 // push twice 163 wb._pushItem(wbItem1) 164 assert.Equal(t, "one,two,three", wb.string(t)) 165 166 // _peekItem 167 assert.Equal(t, wbItem1, wb._peekItem()) 168 169 // _removeItem 170 assert.Equal(t, "one,two,three", wb.string(t)) 171 wb._removeItem(wbItem2) 172 checkNotOnHeap(t, wb, wbItem2) 173 checkInLookup(t, wb, wbItem2) 174 assert.Equal(t, "one,three", wb.string(t)) 175 // remove twice 176 wb._removeItem(wbItem2) 177 checkNotOnHeap(t, wb, wbItem2) 178 checkInLookup(t, wb, wbItem2) 179 assert.Equal(t, "one,three", wb.string(t)) 180 } 181 182 func assertTimerRunning(t *testing.T, wb *WriteBack, running bool) { 183 wb.mu.Lock() 184 if running { 185 assert.NotEqual(t, time.Time{}, wb.expiry) 186 assert.NotNil(t, wb.timer) 187 } else { 188 assert.Equal(t, time.Time{}, wb.expiry) 189 assert.Nil(t, wb.timer) 190 } 191 wb.mu.Unlock() 192 } 193 194 func TestWriteBackResetTimer(t *testing.T) { 195 wb, cancel := newTestWriteBack(t) 196 defer cancel() 197 198 // Reset the timer on an empty queue 199 wb._resetTimer() 200 201 // Check timer is stopped 202 assertTimerRunning(t, wb, false) 203 204 _ = wb._newItem(0, "three") 205 206 // Reset the timer on an queue with stuff 207 wb._resetTimer() 208 209 // Check timer is not stopped 210 assertTimerRunning(t, wb, true) 211 } 212 213 // A "transfer" for testing 214 type putItem struct { 215 wg sync.WaitGroup 216 mu sync.Mutex 217 t *testing.T 218 started chan struct{} 219 errChan chan error 220 running bool 221 cancelled bool 222 called bool 223 } 224 225 func newPutItem(t *testing.T) *putItem { 226 return &putItem{ 227 t: t, 228 started: make(chan struct{}, 1), 229 } 230 } 231 232 // put the object as per PutFn interface 233 func (pi *putItem) put(ctx context.Context) (err error) { 234 pi.wg.Add(1) 235 defer pi.wg.Done() 236 237 pi.mu.Lock() 238 pi.called = true 239 if pi.running { 240 assert.Fail(pi.t, "upload already running") 241 } 242 pi.running = true 243 pi.errChan = make(chan error, 1) 244 pi.mu.Unlock() 245 246 pi.started <- struct{}{} 247 248 cancelled := false 249 select { 250 case err = <-pi.errChan: 251 case <-ctx.Done(): 252 err = ctx.Err() 253 cancelled = true 254 } 255 256 pi.mu.Lock() 257 pi.running = false 258 pi.cancelled = cancelled 259 pi.mu.Unlock() 260 261 return err 262 } 263 264 // finish the "transfer" with the error passed in 265 func (pi *putItem) finish(err error) { 266 pi.mu.Lock() 267 if !pi.running { 268 assert.Fail(pi.t, "upload not running") 269 } 270 pi.mu.Unlock() 271 272 pi.errChan <- err 273 pi.wg.Wait() 274 } 275 276 func waitUntilNoTransfers(t *testing.T, wb *WriteBack) { 277 for i := 0; i < 100; i++ { 278 wb.mu.Lock() 279 uploads := wb.uploads 280 wb.mu.Unlock() 281 if uploads == 0 { 282 return 283 } 284 time.Sleep(10 * time.Millisecond) 285 } 286 t.Errorf("failed to wait for transfer to finish") 287 } 288 289 // This is the happy path with everything working 290 func TestWriteBackAddOK(t *testing.T) { 291 wb, cancel := newTestWriteBack(t) 292 defer cancel() 293 294 pi := newPutItem(t) 295 296 var inID Handle 297 wb.SetID(&inID) 298 assert.Equal(t, Handle(1), inID) 299 300 id := wb.Add(inID, "one", true, pi.put) 301 assert.Equal(t, inID, id) 302 wbItem := wb.lookup[id] 303 checkOnHeap(t, wb, wbItem) 304 checkInLookup(t, wb, wbItem) 305 assert.Equal(t, "one", wb.string(t)) 306 307 <-pi.started 308 checkNotOnHeap(t, wb, wbItem) 309 checkInLookup(t, wb, wbItem) 310 311 pi.finish(nil) // transfer successful 312 waitUntilNoTransfers(t, wb) 313 checkNotOnHeap(t, wb, wbItem) 314 checkNotInLookup(t, wb, wbItem) 315 } 316 317 // Now test the upload failing and being retried 318 func TestWriteBackAddFailRetry(t *testing.T) { 319 wb, cancel := newTestWriteBack(t) 320 defer cancel() 321 322 pi := newPutItem(t) 323 324 id := wb.Add(0, "one", true, pi.put) 325 wbItem := wb.lookup[id] 326 checkOnHeap(t, wb, wbItem) 327 checkInLookup(t, wb, wbItem) 328 assert.Equal(t, "one", wb.string(t)) 329 330 <-pi.started 331 checkNotOnHeap(t, wb, wbItem) 332 checkInLookup(t, wb, wbItem) 333 334 pi.finish(errors.New("transfer failed BOOM")) 335 waitUntilNoTransfers(t, wb) 336 checkOnHeap(t, wb, wbItem) 337 checkInLookup(t, wb, wbItem) 338 339 // check the retry 340 <-pi.started 341 checkNotOnHeap(t, wb, wbItem) 342 checkInLookup(t, wb, wbItem) 343 344 pi.finish(nil) // transfer successful 345 waitUntilNoTransfers(t, wb) 346 checkNotOnHeap(t, wb, wbItem) 347 checkNotInLookup(t, wb, wbItem) 348 } 349 350 // Now test the upload being cancelled by another upload being added 351 func TestWriteBackAddUpdate(t *testing.T) { 352 wb, cancel := newTestWriteBack(t) 353 defer cancel() 354 355 pi := newPutItem(t) 356 357 id := wb.Add(0, "one", true, pi.put) 358 wbItem := wb.lookup[id] 359 checkOnHeap(t, wb, wbItem) 360 checkInLookup(t, wb, wbItem) 361 assert.Equal(t, "one", wb.string(t)) 362 363 <-pi.started 364 checkNotOnHeap(t, wb, wbItem) 365 checkInLookup(t, wb, wbItem) 366 367 // Now the upload has started add another one 368 369 pi2 := newPutItem(t) 370 id2 := wb.Add(id, "one", true, pi2.put) 371 assert.Equal(t, id, id2) 372 checkOnHeap(t, wb, wbItem) // object awaiting writeback time 373 checkInLookup(t, wb, wbItem) 374 375 // check the previous transfer was cancelled 376 assert.True(t, pi.cancelled) 377 378 // check the retry 379 <-pi2.started 380 checkNotOnHeap(t, wb, wbItem) 381 checkInLookup(t, wb, wbItem) 382 383 pi2.finish(nil) // transfer successful 384 waitUntilNoTransfers(t, wb) 385 checkNotOnHeap(t, wb, wbItem) 386 checkNotInLookup(t, wb, wbItem) 387 } 388 389 // Now test the upload being not cancelled by another upload being added 390 func TestWriteBackAddUpdateNotModified(t *testing.T) { 391 wb, cancel := newTestWriteBack(t) 392 defer cancel() 393 394 pi := newPutItem(t) 395 396 id := wb.Add(0, "one", false, pi.put) 397 wbItem := wb.lookup[id] 398 checkOnHeap(t, wb, wbItem) 399 checkInLookup(t, wb, wbItem) 400 assert.Equal(t, "one", wb.string(t)) 401 402 <-pi.started 403 checkNotOnHeap(t, wb, wbItem) 404 checkInLookup(t, wb, wbItem) 405 406 // Now the upload has started add another one 407 408 pi2 := newPutItem(t) 409 id2 := wb.Add(id, "one", false, pi2.put) 410 assert.Equal(t, id, id2) 411 checkNotOnHeap(t, wb, wbItem) // object still being transferred 412 checkInLookup(t, wb, wbItem) 413 414 // Because modified was false above this should not cancel the 415 // transfer 416 assert.False(t, pi.cancelled) 417 418 // wait for original transfer to finish 419 pi.finish(nil) 420 waitUntilNoTransfers(t, wb) 421 checkNotOnHeap(t, wb, wbItem) 422 checkNotInLookup(t, wb, wbItem) 423 424 assert.False(t, pi2.called) 425 } 426 427 // Now test the upload being not cancelled by another upload being 428 // added because the upload hasn't started yet 429 func TestWriteBackAddUpdateNotStarted(t *testing.T) { 430 wb, cancel := newTestWriteBack(t) 431 defer cancel() 432 433 pi := newPutItem(t) 434 435 id := wb.Add(0, "one", true, pi.put) 436 wbItem := wb.lookup[id] 437 checkOnHeap(t, wb, wbItem) 438 checkInLookup(t, wb, wbItem) 439 assert.Equal(t, "one", wb.string(t)) 440 441 // Immediately add another upload before the first has started 442 443 pi2 := newPutItem(t) 444 id2 := wb.Add(id, "one", true, pi2.put) 445 assert.Equal(t, id, id2) 446 checkOnHeap(t, wb, wbItem) // object still awaiting transfer 447 checkInLookup(t, wb, wbItem) 448 449 // Wait for the upload to start 450 <-pi2.started 451 checkNotOnHeap(t, wb, wbItem) 452 checkInLookup(t, wb, wbItem) 453 454 // Because modified was false above this should not cancel the 455 // transfer 456 assert.False(t, pi.cancelled) 457 458 // wait for new transfer to finish 459 pi2.finish(nil) 460 waitUntilNoTransfers(t, wb) 461 checkNotOnHeap(t, wb, wbItem) 462 checkNotInLookup(t, wb, wbItem) 463 464 assert.False(t, pi.called) 465 } 466 467 func TestWriteBackGetStats(t *testing.T) { 468 wb, cancel := newTestWriteBack(t) 469 defer cancel() 470 471 pi := newPutItem(t) 472 473 wb.Add(0, "one", true, pi.put) 474 475 inProgress, queued := wb.Stats() 476 assert.Equal(t, queued, 1) 477 assert.Equal(t, inProgress, 0) 478 479 <-pi.started 480 481 inProgress, queued = wb.Stats() 482 assert.Equal(t, queued, 0) 483 assert.Equal(t, inProgress, 1) 484 485 pi.finish(nil) // transfer successful 486 waitUntilNoTransfers(t, wb) 487 488 inProgress, queued = wb.Stats() 489 assert.Equal(t, queued, 0) 490 assert.Equal(t, inProgress, 0) 491 492 } 493 494 // Test queuing more than fs.Config.Transfers 495 func TestWriteBackMaxQueue(t *testing.T) { 496 ctx := context.Background() 497 ci := fs.GetConfig(ctx) 498 wb, cancel := newTestWriteBack(t) 499 defer cancel() 500 501 maxTransfers := ci.Transfers 502 toTransfer := maxTransfers + 2 503 504 // put toTransfer things in the queue 505 pis := []*putItem{} 506 for i := 0; i < toTransfer; i++ { 507 pi := newPutItem(t) 508 pis = append(pis, pi) 509 wb.Add(0, fmt.Sprintf("number%d", 1), true, pi.put) 510 } 511 512 inProgress, queued := wb.Stats() 513 assert.Equal(t, toTransfer, queued) 514 assert.Equal(t, 0, inProgress) 515 516 // now start the first maxTransfers - this should stop the timer 517 for i := 0; i < maxTransfers; i++ { 518 <-pis[i].started 519 } 520 521 // timer should be stopped now 522 assertTimerRunning(t, wb, false) 523 524 inProgress, queued = wb.Stats() 525 assert.Equal(t, toTransfer-maxTransfers, queued) 526 assert.Equal(t, maxTransfers, inProgress) 527 528 // now finish the first maxTransfers 529 for i := 0; i < maxTransfers; i++ { 530 pis[i].finish(nil) 531 } 532 533 // now start and finish the remaining transfers one at a time 534 for i := maxTransfers; i < toTransfer; i++ { 535 <-pis[i].started 536 pis[i].finish(nil) 537 } 538 waitUntilNoTransfers(t, wb) 539 540 inProgress, queued = wb.Stats() 541 assert.Equal(t, queued, 0) 542 assert.Equal(t, inProgress, 0) 543 } 544 545 func TestWriteBackRename(t *testing.T) { 546 wb, cancel := newTestWriteBack(t) 547 defer cancel() 548 549 // cancel when not in writeback 550 wb.Rename(1, "nonExistent") 551 552 // add item 553 pi1 := newPutItem(t) 554 id := wb.Add(0, "one", true, pi1.put) 555 wbItem := wb.lookup[id] 556 checkOnHeap(t, wb, wbItem) 557 checkInLookup(t, wb, wbItem) 558 assert.Equal(t, wbItem.name, "one") 559 560 // rename when not uploading 561 wb.Rename(id, "two") 562 checkOnHeap(t, wb, wbItem) 563 checkInLookup(t, wb, wbItem) 564 assert.False(t, pi1.cancelled) 565 assert.Equal(t, wbItem.name, "two") 566 567 // add item 568 pi2 := newPutItem(t) 569 id = wb.Add(id, "two", true, pi2.put) 570 wbItem = wb.lookup[id] 571 checkOnHeap(t, wb, wbItem) 572 checkInLookup(t, wb, wbItem) 573 assert.Equal(t, wbItem.name, "two") 574 575 // wait for upload to start 576 <-pi2.started 577 checkNotOnHeap(t, wb, wbItem) 578 checkInLookup(t, wb, wbItem) 579 580 // rename when uploading - goes back on heap 581 wb.Rename(id, "three") 582 checkOnHeap(t, wb, wbItem) 583 checkInLookup(t, wb, wbItem) 584 assert.True(t, pi2.cancelled) 585 assert.Equal(t, wbItem.name, "three") 586 } 587 588 // TestWriteBackRenameDuplicates checks that if we rename an entry and 589 // make a duplicate, we remove the duplicate. 590 func TestWriteBackRenameDuplicates(t *testing.T) { 591 wb, cancel := newTestWriteBack(t) 592 defer cancel() 593 594 // add item "one" 595 pi1 := newPutItem(t) 596 id1 := wb.Add(0, "one", true, pi1.put) 597 wbItem1 := wb.lookup[id1] 598 checkOnHeap(t, wb, wbItem1) 599 checkInLookup(t, wb, wbItem1) 600 assert.Equal(t, wbItem1.name, "one") 601 602 <-pi1.started 603 checkNotOnHeap(t, wb, wbItem1) 604 checkInLookup(t, wb, wbItem1) 605 606 // add item "two" 607 pi2 := newPutItem(t) 608 id2 := wb.Add(0, "two", true, pi2.put) 609 wbItem2 := wb.lookup[id2] 610 checkOnHeap(t, wb, wbItem2) 611 checkInLookup(t, wb, wbItem2) 612 assert.Equal(t, wbItem2.name, "two") 613 614 <-pi2.started 615 checkNotOnHeap(t, wb, wbItem2) 616 checkInLookup(t, wb, wbItem2) 617 618 // rename "two" to "one" 619 wb.Rename(id2, "one") 620 621 // check "one" is cancelled and removed from heap and lookup 622 checkNotOnHeap(t, wb, wbItem1) 623 checkNotInLookup(t, wb, wbItem1) 624 assert.True(t, pi1.cancelled) 625 assert.Equal(t, wbItem1.name, "one") 626 627 // check "two" (now called "one"!) has been cancelled and will 628 // be retried 629 checkOnHeap(t, wb, wbItem2) 630 checkInLookup(t, wb, wbItem2) 631 assert.True(t, pi2.cancelled) 632 assert.Equal(t, wbItem2.name, "one") 633 } 634 635 func TestWriteBackCancelUpload(t *testing.T) { 636 wb, cancel := newTestWriteBack(t) 637 defer cancel() 638 639 // cancel when not in writeback 640 assert.False(t, wb.cancelUpload(1)) 641 642 // add item 643 pi := newPutItem(t) 644 id := wb.Add(0, "one", true, pi.put) 645 wbItem := wb.lookup[id] 646 checkOnHeap(t, wb, wbItem) 647 checkInLookup(t, wb, wbItem) 648 649 // cancel when not uploading 650 assert.False(t, wb.cancelUpload(id)) 651 checkOnHeap(t, wb, wbItem) 652 checkInLookup(t, wb, wbItem) 653 654 // wait for upload to start 655 <-pi.started 656 checkNotOnHeap(t, wb, wbItem) 657 checkInLookup(t, wb, wbItem) 658 659 // cancel when uploading 660 assert.True(t, wb.cancelUpload(id)) 661 checkOnHeap(t, wb, wbItem) 662 checkInLookup(t, wb, wbItem) 663 assert.True(t, pi.cancelled) 664 }