revid: gave AudioDevice a logger

revid/audio-input.go

@@ -55,12 +55,11 @@ const (
 // Rates contains the audio sample rates used by revid.
 var Rates = [8]int{8000, 16000, 32000, 44100, 48000, 88200, 96000, 192000}
 
-var log *logger.Logger
-
 // AudioDevice holds everything we need to know about the audio input stream.
 // Note: At 44100 Hz sample rate, 2 channels and 16-bit samples, a period of 5 seconds
 // results in PCM data chunks of 882000 bytes. A longer period exceeds datastore's 1MB blob limit.
 type AudioDevice struct {
+	l      Logger
 	mu     sync.Mutex
 	source string // Name of audio source, or empty for the default source.
 	mode   uint8  // Operating mode, either running, paused, or stopped.
@@ -84,6 +83,9 @@ type AudioConfig struct {
 
 // NewAudioDevice initializes and returns an AudioDevice struct which can be started, read from, and stopped.
 func NewAudioDevice(cfg *AudioConfig) *AudioDevice {
+	a := &AudioDevice{}
+	a.AudioConfig = cfg
+
 	// Initialize logger.
 	logLevel := int(logger.Debug)
 	validLogLevel := true
@@ -92,26 +94,23 @@ func NewAudioDevice(cfg *AudioConfig) *AudioDevice {
 		validLogLevel = false
 	}
 	logSender := smartlogger.New(logPath)
-	log = logger.New(int8(logLevel), &logSender.LogRoller)
-	log.Log(logger.Info, "log-netsender: Logger Initialized")
+	a.l = logger.New(int8(logLevel), &logSender.LogRoller)
+	a.l.Log(logger.Info, "log-netsender: Logger Initialized")
 	if !validLogLevel {
-		log.Log(logger.Error, "Invalid log level was defaulted to Info")
+		a.l.Log(logger.Error, "Invalid log level was defaulted to Info")
 	}
 
-	a := &AudioDevice{}
-	a.AudioConfig = cfg
-
 	// Open the requested audio device.
 	err := a.open()
 	if err != nil {
-		log.Log(logger.Fatal, "alsa.open failed", "error", err.Error())
+		a.l.Log(logger.Fatal, "alsa.open failed", "error", err.Error())
 	}
 
 	// Setup ring buffer to capture audio in periods of a.RecPeriod seconds, and buffer rbDuration seconds in total.
 	a.ab = a.dev.NewBufferDuration(time.Duration(a.RecPeriod * float64(time.Second)))
 	cs := (float64((len(a.ab.Data)/a.dev.BufferFormat().Channels)*a.Channels) / float64(a.dev.BufferFormat().Rate)) * float64(a.SampleRate)
 	if cs < 1 {
-		log.Log(logger.Fatal, "given AudioConfig parameters are too small")
+		a.l.Log(logger.Fatal, "given AudioConfig parameters are too small")
 	}
 	a.chunkSize = int(cs)
 	a.rb = ring.NewBuffer(rbLen, a.chunkSize, rbTimeout)
@@ -140,7 +139,7 @@ func (a *AudioDevice) Start() {
 		// Open the audio device and start recording.
 		err := a.open()
 		if err != nil {
-			log.Log(logger.Fatal, "alsa.open failed", "error", err.Error())
+			a.l.Log(logger.Fatal, "alsa.open failed", "error", err.Error())
 		}
 		go a.input()
 		a.mode = running
@@ -156,7 +155,7 @@ func (a *AudioDevice) Stop() {
 	fmt.Println("stop lock")
 	a.mu.Lock()
 	if a.dev != nil {
-		log.Log(logger.Debug, "Closing", "source", a.source)
+		a.l.Log(logger.Debug, "Closing", "source", a.source)
 		a.dev.Close()
 		a.dev = nil
 	}
@@ -175,11 +174,11 @@ func (a *AudioDevice) ChunkSize() int {
 // If name is empty, the first recording device is used.
 func (a *AudioDevice) open() error {
 	if a.dev != nil {
-		log.Log(logger.Debug, "Closing", "source", a.source)
+		a.l.Log(logger.Debug, "Closing", "source", a.source)
 		a.dev.Close()
 		a.dev = nil
 	}
-	log.Log(logger.Debug, "Opening", "source", a.source)
+	a.l.Log(logger.Debug, "Opening", "source", a.source)
 
 	cards, err := alsa.OpenCards()
 	if err != nil {
@@ -206,14 +205,14 @@ func (a *AudioDevice) open() error {
 	if a.dev == nil {
 		return errors.New("No audio source found")
 	}
-	log.Log(logger.Debug, "Found audio source", "source", a.dev.Title)
+	a.l.Log(logger.Debug, "Found audio source", "source", a.dev.Title)
 
 	// ToDo: time out if Open takes too long.
 	err = a.dev.Open()
 	if err != nil {
 		return err
 	}
-	log.Log(logger.Debug, "Opened audio source")
+	a.l.Log(logger.Debug, "Opened audio source")
 
 	// 2 channels is what most devices need to record in. If mono is requested,
 	// the recording will be converted in formatBuffer().
@@ -236,19 +235,19 @@ func (a *AudioDevice) open() error {
 			_, err = a.dev.NegotiateRate(Rates[i])
 			if err == nil {
 				foundRate = true
-				log.Log(logger.Debug, "Sample rate set", "rate", Rates[i])
+				a.l.Log(logger.Debug, "Sample rate set", "rate", Rates[i])
 			}
 		}
 	}
 
 	// If no easily divisible rate is found, then use the default rate.
 	if !foundRate {
-		log.Log(logger.Warning, "Unable to sample at requested rate, default used.", "rateRequested", a.SampleRate)
+		a.l.Log(logger.Warning, "Unable to sample at requested rate, default used.", "rateRequested", a.SampleRate)
 		_, err = a.dev.NegotiateRate(defaultSampleRate)
 		if err != nil {
 			return err
 		}
-		log.Log(logger.Debug, "Sample rate set", "rate", defaultSampleRate)
+		a.l.Log(logger.Debug, "Sample rate set", "rate", defaultSampleRate)
 	}
 
 	var aFmt alsa.FormatType
@@ -274,7 +273,7 @@ func (a *AudioDevice) open() error {
 	if err = a.dev.Prepare(); err != nil {
 		return err
 	}
-	log.Log(logger.Debug, "Successfully negotiated ALSA params")
+	a.l.Log(logger.Debug, "Successfully negotiated ALSA params")
 	return nil
 }
 
@@ -305,17 +304,17 @@ func (a *AudioDevice) input() {
 			fmt.Println("input unlock")
 			return
 		}
-		log.Log(logger.Debug, "Recording audio for period", "seconds", a.RecPeriod)
+		a.l.Log(logger.Debug, "Recording audio for period", "seconds", a.RecPeriod)
 		fmt.Println("LEN:", len(a.ab.Data))
 		err := a.dev.Read(a.ab.Data)
 		fmt.Println("input read")
 		if err != nil {
-			log.Log(logger.Debug, "Device.Read failed", "error", err.Error())
+			a.l.Log(logger.Debug, "Device.Read failed", "error", err.Error())
 			err = a.open() // re-open
 			if err != nil {
 				a.mu.Unlock()
 				fmt.Println("input unlock")
-				log.Log(logger.Fatal, "alsa.open failed", "error", err.Error())
+				a.l.Log(logger.Fatal, "alsa.open failed", "error", err.Error())
 			}
 			a.mu.Unlock()
 			fmt.Println("input unlock")
@@ -325,20 +324,20 @@ func (a *AudioDevice) input() {
 		toWrite := a.formatBuffer()
 		fmt.Println("input point")
 
-		log.Log(logger.Debug, "Audio format conversion has been performed where needed")
+		a.l.Log(logger.Debug, "Audio format conversion has been performed where needed")
 
 		var n int
 		n, err = a.rb.Write(toWrite.Data)
 		fmt.Println("input write")
 		switch err {
 		case nil:
-			log.Log(logger.Debug, "Wrote audio to ringbuffer", "length", n)
+			a.l.Log(logger.Debug, "Wrote audio to ringbuffer", "length", n)
 		case ring.ErrDropped:
-			log.Log(logger.Warning, "Dropped audio")
+			a.l.Log(logger.Warning, "Dropped audio")
 		default:
 			a.mu.Unlock()
 			fmt.Println("input unlock")
-			log.Log(logger.Error, "Unexpected ringbuffer error", "error", err.Error())
+			a.l.Log(logger.Error, "Unexpected ringbuffer error", "error", err.Error())
 			return
 		}
 		a.mu.Unlock()
@@ -369,18 +368,18 @@ func (a *AudioDevice) Read(p []byte) (n int, err error) {
 	case ring.ErrTimeout:
 		return 0, nil
 	case io.EOF:
-		log.Log(logger.Error, "Unexpected EOF from ring.Next")
+		a.l.Log(logger.Error, "Unexpected EOF from ring.Next")
 		return 0, io.ErrUnexpectedEOF
 	default:
-		log.Log(logger.Error, "Unexpected error from ring.Next", "error", err.Error())
+		a.l.Log(logger.Error, "Unexpected error from ring.Next", "error", err.Error())
 		return 0, err
 	}
 	n, err = io.ReadFull(a.rb, p[:chunk.Len()])
 	if err != nil {
-		log.Log(logger.Error, "Unexpected error from ring.Read", "error", err.Error())
+		a.l.Log(logger.Error, "Unexpected error from ring.Read", "error", err.Error())
 		return n, err
 	}
-	log.Log(logger.Debug, "Read audio from ringbuffer", "length", n)
+	a.l.Log(logger.Debug, "Read audio from ringbuffer", "length", n)
 	a.mu.Unlock()
 	fmt.Println("read unlock")
 	return n, nil
@@ -405,7 +404,7 @@ func (a *AudioDevice) formatBuffer() alsa.Buffer {
 		// Convert channels.
 		if a.ab.Format.Channels == 2 && wantChannels == 1 {
 			if formatted.Data, err = pcm.StereoToMono(a.ab); err != nil {
-				log.Log(logger.Warning, "Channel conversion failed, audio has remained stereo", "error", err.Error())
+				a.l.Log(logger.Warning, "Channel conversion failed, audio has remained stereo", "error", err.Error())
 			} else {
 				formatted.Format.Channels = 1
 			}
@@ -422,7 +421,7 @@ func (a *AudioDevice) formatBuffer() alsa.Buffer {
 			formatted.Data, err = pcm.Resample(a.ab, wantRate)
 		}
 		if err != nil {
-			log.Log(logger.Warning, "Rate conversion failed, audio has remained original rate", "error", err.Error())
+			a.l.Log(logger.Warning, "Rate conversion failed, audio has remained original rate", "error", err.Error())
 		} else {
 			formatted.Format.Rate = wantRate
 		}

revid/audio-input_test.go

@@ -106,8 +106,8 @@ func TestAudio(t *testing.T) {
 	ai := NewAudioDevice(ac)
 	dst := bytes.NewBuffer(make([]byte, 0))
 	ai.Start()
+	num := 3 // How many 'ac.RecPeriod's to record.
 	go lex.ADPCM(dst, ai, time.Duration(ac.RecPeriod*float64(time.Second)), ai.ChunkSize())
-	time.Sleep(time.Millisecond * 30)
+	time.Sleep(time.Millisecond * 100 * time.Duration(num))
 	ai.Stop()
-
 }

revid/revid_test.go

@@ -41,7 +41,7 @@ import (
 const raspividPath = "/usr/local/bin/raspivid"
 
 // Suppress all test logging, except for t.Errorf output.
-var silent bool
+var silent bool = true
 
 // TestRaspivid tests that raspivid starts correctly.
 // It is intended to be run on a Raspberry Pi.