Add logger

cmd/gen.go

@@ -49,7 +49,10 @@ var genCmd = &cobra.Command{
 		//iroha.PrintWordCountMap()
 		//iroha.PrintWordByKatakanaMap()
 		log.Print("start searching...")
-		rowIndicesList := iroha.Search()
+		rowIndicesList, err := iroha.Search()
+		if err != nil {
+			panic(err)
+		}
 
 		for _, rowIndices := range rowIndicesList {
 			for _, rowIndex := range rowIndices {

lib/iroha.go

@@ -7,6 +7,7 @@ import (
 type Iroha struct {
 	katakanaBitsMap KatakanaBitsMap
 	katakana        *Katakana
+	log             *Log
 }
 
 func NewIroha(words []string) *Iroha {
@@ -25,9 +26,13 @@ func (i *Iroha) PrintWordByKatakanaMap() {
 	i.katakana.PrintWordByKatakanaMap()
 }
 
-func (i *Iroha) Search() (rowIndicesList [][]int) {
+func (i *Iroha) Search() (rowIndicesList [][]int, err error) {
 	katakanaBitsAndWordsList := i.katakana.ListSortedKatakanaBitsAndWords()
-	wordsList, _ := i.searchByBits(katakanaBitsAndWordsList, WordBits(0))
+	i.log = NewLog(katakanaBitsAndWordsList)
+	wordsList, _, err := i.searchByBits(katakanaBitsAndWordsList, WordBits(0))
+	if err != nil {
+		return nil, err
+	}
 	for _, words := range wordsList {
 		var rowIndices []int
 		for _, word := range words {
@@ -38,36 +43,50 @@ func (i *Iroha) Search() (rowIndicesList [][]int) {
 	return
 }
 
-func (i *Iroha) searchByBits(katakanaBitsAndWords []*KatakanaBitsAndWords, remainKatakanaBits WordBits) ([][]*Word, bool) {
-	if bits.OnesCount64(uint64(remainKatakanaBits)) == int(KatakanaLen) {
-		return [][]*Word{{}}, true
+func (i *Iroha) searchByBits(katakanaBitsAndWords []*KatakanaBitsAndWords, remainKatakanaBits WordBits) ([][]*Word, bool, error) {
+	remainKatakanaNum := bits.OnesCount64(uint64(remainKatakanaBits))
+	if remainKatakanaNum == int(KatakanaLen) {
+		return [][]*Word{{}}, true, nil
 	}
 
 	if len(katakanaBitsAndWords) == 0 {
-		return nil, false
+		return nil, false, nil
 	}
 
 	katakanaAndWordBits := katakanaBitsAndWords[0]
+	depth := int(KatakanaLen) - len(katakanaBitsAndWords)
 	var irohaWordLists [][]*Word
-	for _, word := range katakanaAndWordBits.Words {
+	for cur, word := range katakanaAndWordBits.Words {
+		measurer := NewTimeMeasurerAndStart()
 		if remainKatakanaBits.HasDuplicatedKatakana(word.Bits) {
 			continue
 		}
 		newRemainKatakanaBits := remainKatakanaBits.Merge(word.Bits)
-		if newIrohaWordIdLists, ok := i.searchByBits(katakanaBitsAndWords[1:], newRemainKatakanaBits); ok {
+		newIrohaWordIdLists, ok, err := i.searchByBits(katakanaBitsAndWords[1:], newRemainKatakanaBits)
+		if err != nil {
+			return nil, false, err
+		}
+		if ok {
 			for _, newIrohaWordList := range newIrohaWordIdLists {
 				newIrohaWordList = append(newIrohaWordList, word)
 				irohaWordLists = append(irohaWordLists, newIrohaWordList)
 			}
 		}
+		if t := measurer.GetElapsedTimeSec(); t > 5 {
+			i.log.PrintProgressLog(depth, cur, t)
+		}
 	}
 
 	// どれも入れない場合
 	if remainKatakanaBits.has(katakanaAndWordBits.KatakanaBits) {
-		if otherIrohaWordBitsLists, ok := i.searchByBits(katakanaBitsAndWords[1:], remainKatakanaBits); ok {
+		otherIrohaWordBitsLists, ok, err := i.searchByBits(katakanaBitsAndWords[1:], remainKatakanaBits)
+		if err != nil {
+			return nil, false, err
+		}
+		if ok {
 			irohaWordLists = append(irohaWordLists, otherIrohaWordBitsLists...)
 		}
 	}
 
-	return irohaWordLists, len(irohaWordLists) > 0
+	return irohaWordLists, len(irohaWordLists) > 0, nil
 }

lib/log.go

@@ -0,0 +1,70 @@
+package lib
+
+import (
+	"log"
+)
+
+type Log struct {
+	counts   []int
+	curs     []int
+	measurer *TimeMeasurer
+}
+
+func NewLog(katakanaBitsAndWordsList []*KatakanaBitsAndWords) *Log {
+	counts := make([]int, len(katakanaBitsAndWordsList), len(katakanaBitsAndWordsList))
+	for index, katakanaBitsAndWords := range katakanaBitsAndWordsList {
+		counts[index] = len(katakanaBitsAndWords.Words)
+	}
+	countsSum := 0
+	for _, count := range counts {
+		countsSum += count
+	}
+	log.Printf("counts: %.2v %d\n", counts, countsSum)
+
+	return &Log{
+		counts:   counts,
+		curs:     make([]int, len(counts), len(counts)),
+		measurer: NewTimeMeasurer(),
+	}
+}
+
+func (l *Log) updateProgress(depth, cur int) {
+	l.curs[depth] = cur
+	for i := range l.curs {
+		if i <= depth {
+			continue
+		}
+		l.curs[i] = 0
+	}
+}
+
+func (l *Log) getProgress(depth int) float64 {
+	max := float64(l.counts[0])
+	cur := float64(l.curs[0])
+	for index, count := range l.counts[1 : depth+1] {
+		max *= float64(count)
+		cur *= float64(l.curs[index])
+	}
+	return (cur / max) * 100
+}
+
+func (l *Log) PrintProgressLog(depth, current int, sec float64) {
+	log.Printf("depth: %v %v/%v, take %.2f sec. %f%s",
+		depth,
+		current,
+		l.counts[depth],
+		sec,
+		l.getProgress(depth),
+		"%",
+	)
+	l.updateProgress(depth, current)
+	percents := make([]float64, len(l.curs), len(l.curs))
+	for i, cur := range l.curs {
+		if l.counts[i] == 0 {
+			percents[i] = 0
+			continue
+		}
+		percents[i] = (float64(cur) / float64(l.counts[i])) * 100
+	}
+	log.Printf("percents: %.2v", percents)
+}

lib/time_measurer.go

@@ -0,0 +1,28 @@
+package lib
+
+import (
+	"time"
+)
+
+type TimeMeasurer struct {
+	start time.Time
+}
+
+func NewTimeMeasurer() *TimeMeasurer {
+	return &TimeMeasurer{}
+}
+
+func NewTimeMeasurerAndStart() *TimeMeasurer {
+	t := NewTimeMeasurer()
+	t.Start()
+	return t
+}
+
+func (t *TimeMeasurer) Start() {
+	t.start = time.Now()
+}
+
+func (t *TimeMeasurer) GetElapsedTimeSec() float64 {
+	end := time.Now()
+	return end.Sub(t.start).Seconds()
+}