From 148039cae7d9c4260b290a97414b2f22495a8759 Mon Sep 17 00:00:00 2001
From: Tom Clegg <tom@tomclegg.ca>
Date: Thu, 5 Mar 2020 13:52:10 -0500
Subject: [PATCH] Less verbose logging.

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tom@tomclegg.ca>
---
 arvados.go     |  2 +-
 exportnumpy.go |  2 +-
 filter.go      |  2 +-
 go.mod         |  1 +
 import.go      |  4 ++--
 tilelib.go     | 17 ++++++++++++-----
 6 files changed, 18 insertions(+), 10 deletions(-)

diff --git a/arvados.go b/arvados.go
index f409e3b647..9cef74a21c 100644
--- a/arvados.go
+++ b/arvados.go
@@ -5,7 +5,6 @@ import (
 	"errors"
 	"fmt"
 	"io/ioutil"
-	"log"
 	"net/url"
 	"os"
 	"regexp"
@@ -15,6 +14,7 @@ import (
 	"git.arvados.org/arvados.git/sdk/go/arvados"
 	"git.arvados.org/arvados.git/sdk/go/arvadosclient"
 	"git.arvados.org/arvados.git/sdk/go/keepclient"
+	log "github.com/sirupsen/logrus"
 	"golang.org/x/crypto/blake2b"
 	"golang.org/x/net/websocket"
 )
diff --git a/exportnumpy.go b/exportnumpy.go
index 8ccf11e707..bab360aaeb 100644
--- a/exportnumpy.go
+++ b/exportnumpy.go
@@ -7,13 +7,13 @@ import (
 	"fmt"
 	"io"
 	"io/ioutil"
-	"log"
 	"net/http"
 	_ "net/http/pprof"
 	"os"
 
 	"git.arvados.org/arvados.git/sdk/go/arvados"
 	"github.com/kshedden/gonpy"
+	log "github.com/sirupsen/logrus"
 )
 
 type exportNumpy struct{}
diff --git a/filter.go b/filter.go
index 247e00f782..d5aa0d1bfb 100644
--- a/filter.go
+++ b/filter.go
@@ -8,12 +8,12 @@ import (
 	"fmt"
 	"io"
 	"io/ioutil"
-	"log"
 	"net/http"
 	_ "net/http/pprof"
 	"os"
 
 	"git.arvados.org/arvados.git/sdk/go/arvados"
+	log "github.com/sirupsen/logrus"
 )
 
 type filterer struct {
diff --git a/go.mod b/go.mod
index 77753a2230..f5dadd9c43 100644
--- a/go.mod
+++ b/go.mod
@@ -10,6 +10,7 @@ require (
 	github.com/kshedden/gonpy v0.0.0-20190510000443-66c21fac4672
 	github.com/prometheus/client_golang v1.5.0 // indirect
 	github.com/prometheus/procfs v0.0.10 // indirect
+	github.com/sirupsen/logrus v1.4.2
 	golang.org/x/crypto v0.0.0-20200302210943-78000ba7a073
 	golang.org/x/net v0.0.0-20200301022130-244492dfa37a
 	golang.org/x/sys v0.0.0-20200302150141-5c8b2ff67527 // indirect
diff --git a/import.go b/import.go
index 2c502a47cf..98c10254bf 100644
--- a/import.go
+++ b/import.go
@@ -8,7 +8,6 @@ import (
 	"flag"
 	"fmt"
 	"io"
-	"log"
 	"net/http"
 	_ "net/http/pprof"
 	"os"
@@ -23,6 +22,7 @@ import (
 	"time"
 
 	"git.arvados.org/arvados.git/sdk/go/arvados"
+	log "github.com/sirupsen/logrus"
 )
 
 type importer struct {
@@ -117,7 +117,7 @@ func (cmd *importer) RunCommand(prog string, args []string, stdin io.Reader, std
 		return 1
 	}
 	go func() {
-		for range time.Tick(10 * time.Second) {
+		for range time.Tick(10 * time.Minute) {
 			log.Printf("tilelib.Len() == %d", tilelib.Len())
 		}
 	}()
diff --git a/tilelib.go b/tilelib.go
index 13df225e13..7b90810242 100644
--- a/tilelib.go
+++ b/tilelib.go
@@ -4,10 +4,10 @@ import (
 	"bufio"
 	"bytes"
 	"io"
-	"log"
 	"strings"
 	"sync"
 
+	log "github.com/sirupsen/logrus"
 	"golang.org/x/crypto/blake2b"
 )
 
@@ -65,7 +65,7 @@ func (tilelib *tileLibrary) TileFasta(filelabel string, rdr io.Reader) (tileSeq,
 			if len(buf) == 0 || buf[0] == '>' {
 				todo <- jobT{seqlabel, fasta}
 				seqlabel, fasta = string(buf[1:]), nil
-				log.Printf("%s %s reading fasta", filelabel, seqlabel)
+				log.Debugf("%s %s reading fasta", filelabel, seqlabel)
 			} else {
 				fasta = append(fasta, bytes.ToLower(buf)...)
 			}
@@ -73,11 +73,16 @@ func (tilelib *tileLibrary) TileFasta(filelabel string, rdr io.Reader) (tileSeq,
 		todo <- jobT{seqlabel, fasta}
 	}()
 	path := make([]tileLibRef, 2000000)
+	totalPathLen := 0
+	skippedSequences := 0
 	for job := range todo {
-		if len(job.fasta) == 0 || strings.Contains(job.label, "_") {
+		if len(job.fasta) == 0 {
+			continue
+		} else if strings.Contains(job.label, "_") {
+			skippedSequences++
 			continue
 		}
-		log.Printf("%s %s tiling", filelabel, job.label)
+		log.Debugf("%s %s tiling", filelabel, job.label)
 		path = path[:0]
 		tilestart := -1        // position in fasta of tile that ends here
 		tiletagid := tagID(-1) // tag id starting tile that ends here
@@ -94,8 +99,10 @@ func (tilelib *tileLibrary) TileFasta(filelabel string, rdr io.Reader) (tileSeq,
 		pathcopy := make([]tileLibRef, len(path))
 		copy(pathcopy, path)
 		ret[job.label] = pathcopy
-		log.Printf("%s %s tiled with path len %d", filelabel, job.label, len(path))
+		log.Debugf("%s %s tiled with path len %d", filelabel, job.label, len(path))
+		totalPathLen += len(path)
 	}
+	log.Printf("%s tiled with total path len %d in %d sequences (skipped %d sequences with '_' in name)", filelabel, totalPathLen, len(ret), skippedSequences)
 	return ret, scanner.Err()
 }
 
-- 
2.30.2