test: add some debug logs for scanning

#63

server/ctrladmin/handlers.go

@@ -26,7 +26,9 @@ func firstExisting(or string, strings ...string) string {
 }
 
 func doScan(scanner *scanner.Scanner, opts scanner.ScanOptions) {
+	log.Printf("+++ admin scan b\n")
 	go func() {
+		log.Printf("+++ admin scan c\n")
 		if err := scanner.Start(opts); err != nil {
 			log.Printf("error while scanning: %v\n", err)
 		}
@@ -364,6 +366,7 @@ func (c *Controller) ServeUpdateLastFMAPIKeyDo(r *http.Request) *Response {
 }
 
 func (c *Controller) ServeStartScanIncDo(r *http.Request) *Response {
+	log.Printf("+++ admin scan a\n")
 	defer doScan(c.Scanner, scanner.ScanOptions{})
 	return &Response{
 		redirect: "/admin/home",
@@ -372,6 +375,7 @@ func (c *Controller) ServeStartScanIncDo(r *http.Request) *Response {
 }
 
 func (c *Controller) ServeStartScanFullDo(r *http.Request) *Response {
+	log.Printf("+++ admin full scan a\n")
 	defer doScan(c.Scanner, scanner.ScanOptions{IsFull: true})
 	return &Response{
 		redirect: "/admin/home",

server/ctrlsubsonic/handlers_common.go

@@ -76,7 +76,9 @@ func (c *Controller) ServeGetMusicFolders(r *http.Request) *spec.Response {
 }
 
 func (c *Controller) ServeStartScan(r *http.Request) *spec.Response {
+	log.Printf("+++ pre scanning from subsonic controller\n")
 	go func() {
+		log.Printf("+++ scanning from subsonic controller\n")
 		if err := c.Scanner.Start(scanner.ScanOptions{}); err != nil {
 			log.Printf("error while scanning: %v\n", err)
 		}

server/scanner/scanner.go

@@ -51,8 +51,10 @@ func IsScanning() bool {
 }
 
 func SetScanning() func() {
+	log.Printf("+++ atomic set scanning\n")
 	atomic.StoreInt32(&isScanning, 1)
 	return func() {
+		log.Printf("+++ atomic unset scanning\n")
 		atomic.StoreInt32(&isScanning, 0)
 	}
 }
@@ -178,6 +180,7 @@ type ScanOptions struct {
 
 func (s *Scanner) Start(opts ScanOptions) error {
 	if IsScanning() {
+		log.Printf("+++ not scanning\n")
 		return ErrAlreadyScanning
 	}
 	unSet := SetScanning()
@@ -189,6 +192,7 @@ func (s *Scanner) Start(opts ScanOptions) error {
 	s.curFolders = &stack.Stack{}
 	s.seenTracksNew = 0
 	// ** begin being walking
+	log.Printf("+++ starting normal scan\n")
 	log.Println("starting scan")
 	var errCount int
 	start := time.Now()
@@ -234,6 +238,7 @@ func (s *Scanner) Start(opts ScanOptions) error {
 			clean.name, durSince(start), deleted)
 	}
 	// finish up
+	log.Printf("+++ finished scanning\n")
 	strNow := strconv.FormatInt(time.Now().Unix(), 10)
 	s.db.SetSetting("last_scan_time", strNow)
 	return nil

server/server.go

@@ -269,8 +269,10 @@ func (s *Server) StartScanTicker(dur time.Duration) (FuncExecute, FuncInterrupt)
 		for {
 			select {
 			case <-done:
+				log.Printf("+++ tick done %v\n", dur)
 				return nil
 			case <-ticker.C:
+				log.Printf("+++ tick scanner %v\n", dur)
 				if err := s.scanner.Start(scanner.ScanOptions{}); err != nil {
 					log.Printf("error scanning: %v", err)
 				}