Golang Logger.Printf方法代码示例

func (a *BuyActivity) sendMissingChunksAndReturnResult(log bitwrk.Logger, client *http.Client, wishList []byte) (io.ReadCloser, error) {
	// Send data of missing chunks to seller
	pipeIn, pipeOut := io.Pipe()
	defer pipeIn.Close()
	mwriter := multipart.NewWriter(pipeOut)

	// Write work chunks into pipe for HTTP request
	go func() {
		defer pipeOut.Close()
		if part, err := mwriter.CreateFormFile("chunkdata", "chunkdata.bin"); err != nil {
			pipeOut.CloseWithError(err)
			return
		} else if err := cafs.WriteRequestedChunks(a.workFile, wishList, part); err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		if err := mwriter.Close(); err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		log.Printf("Missing chunk data transmitted successfully.")
	}()

	if r, err := a.postToSeller(pipeIn, mwriter.FormDataContentType(), client); err != nil {
		return nil, fmt.Errorf("Error sending work chunk data to seller: %v", err)
	} else {
		return r, nil
	}
}

// Closes resources upon exit of a function or when some condition no longer holds
// Arguments:
//  - exitChan: Signals the watchdog to exit
//  - closerChan: Signals the watchdog to add an io.Closer to the list of closers
//  - f: Defines the OK condition. When false, all current closers are closed
func (t *Trade) watchdog(log bitwrk.Logger, exitChan <-chan bool, closerChan <-chan io.Closer, f func() bool) {
	closers := make([]io.Closer, 0, 1)
	for {
		select {
		case closer := <-closerChan:
			closers = append(closers, closer)
		case <-exitChan:
			// Exit from watchdog if surrounding function has terminated
			log.Print("Watchdog exiting by request")
			return
		default:
		}

		// Check if condition still holds
		t.condition.L.Lock()
		ok := f()
		t.condition.L.Unlock()
		if !ok {
			log.Printf("Watchdog: closing %v channels", len(closers))
			for _, c := range closers {
				err := c.Close()
				if err != nil {
					log.Printf("Error closing channel: %v", err)
				}
			}
			closers = closers[:0] // clear list of current closers
		}

		time.Sleep(250 * time.Millisecond)
	}
}

func (a *BuyActivity) requestMissingChunks(log bitwrk.Logger, client *http.Client) (io.ReadCloser, error) {
	// Send chunk list of work to client
	pipeIn, pipeOut := io.Pipe()
	defer pipeIn.Close()
	mwriter := multipart.NewWriter(pipeOut)

	// Write chunk hashes into pipe for HTTP request
	go func() {
		defer pipeOut.Close()
		if err := a.encodeChunkedFirstTransmission(log, mwriter); err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		if err := mwriter.Close(); err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		log.Printf("Work chunk hashes transmitted successfully.")
	}()

	if r, err := a.postToSeller(pipeIn, mwriter.FormDataContentType(), false, client); err != nil {
		return nil, fmt.Errorf("Error sending work chunk hashes to seller: %v", err)
	} else {
		return r, nil
	}
}

func (t *Trade) updateTransaction(log bitwrk.Logger) error {
	attemptsLeft := 3
	for attemptsLeft > 0 {
		attemptsLeft--
		if tx, etag, err := FetchTx(t.txId, ""); err != nil {
			log.Printf("Error updating transaction: %v (attempts left: %d)", err, attemptsLeft)
			if attemptsLeft > 0 {
				time.Sleep(5 * time.Second)
			} else {
				return err
			}
		} else {
			expired := false
			func() {
				t.condition.L.Lock()
				defer t.condition.L.Unlock()
				if etag != t.txETag {
					t.tx = tx
					t.txETag = etag
					expired = t.tx.State != bitwrk.StateActive
					t.condition.Broadcast()
					log.Printf("Tx change detected: phase=%v, expired=%v", t.tx.Phase, expired)
				}
			}()
			if expired {
				break
			}
		}
	}
	return nil
}

func (s *WorkerState) offer(log bitwrk.Logger) {
	defer log.Printf("Stopped offering")
	s.cond.L.Lock()
	defer s.cond.L.Unlock()
	interrupt := make(chan bool, 1)
	for {
		// Interrupt if unregistered, stop iterating
		if s.Unregistered {
			log.Printf("No longer registered")
			interrupt <- true
			break
		}
		if s.Blockers == 0 {
			s.LastError = ""
			if sell, err := s.m.activityManager.NewSell(s); err != nil {
				s.LastError = fmt.Sprintf("Error creating sell: %v", err)
				log.Println(s.LastError)
				s.blockFor(20 * time.Second)
			} else {
				s.Blockers++
				go s.executeSell(log, sell, interrupt)
			}
		}
		s.cond.Wait()
	}
}

func (a *BuyActivity) sendMissingChunksAndReturnResult(log bitwrk.Logger, client *http.Client, wishList []byte, compressed bool) (io.ReadCloser, error) {
	// Send data of missing chunks to seller
	pipeIn, pipeOut := io.Pipe()
	defer pipeIn.Close()

	// Setup compression layer with dummy impl in case of uncompressed transmisison
	var compressor io.Writer
	var closeCompressor func() error
	if compressed {
		c := gzip.NewWriter(pipeOut)
		compressor = c
		closeCompressor = c.Close
	} else {
		compressor = pipeOut
		closeCompressor = func() error { return nil }
	}

	mwriter := multipart.NewWriter(compressor)

	// Communicate status back
	progressCallback := func(bytesToTransfer, bytesTransferred uint64) {
		a.execSync(func() {
			a.bytesToTransfer = bytesToTransfer
			a.bytesTransferred = bytesTransferred
		})
	}

	// Write work chunks into pipe for HTTP request
	go func() {
		defer pipeOut.Close()
		if part, err := mwriter.CreateFormFile("chunkdata", "chunkdata.bin"); err != nil {
			pipeOut.CloseWithError(err)
			return
		} else if err := cafs.WriteRequestedChunks(a.workFile, wishList, part, progressCallback); err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		if err := mwriter.Close(); err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		if err := closeCompressor(); err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		log.Printf("Missing chunk data transmitted successfully.")
	}()

	if r, err := a.postToSeller(pipeIn, mwriter.FormDataContentType(), compressed, client); err != nil {
		return nil, fmt.Errorf("Error sending work chunk data to seller: %v", err)
	} else {
		return r, nil
	}
}

func (a *BuyActivity) encodeChunkedFirstTransmission(log bitwrk.Logger, mwriter *multipart.Writer) (err error) {
	part, err := mwriter.CreateFormFile("a32chunks", "a32chunks.bin")
	if err != nil {
		return
	}
	log.Printf("Sending work chunk hashes to seller [%v].", *a.tx.WorkerURL)
	err = cafs.WriteChunkHashes(a.workFile, part)
	if err != nil {
		return
	}
	log.Printf("Sending buyer's secret to seller.")
	err = mwriter.WriteField("buyersecret", a.buyerSecret.String())
	if err != nil {
		return
	}
	return mwriter.Close()
}

func (s *WorkerState) executeSell(log bitwrk.Logger, sell *SellActivity, interrupt <-chan bool) {
	defer func() {
		s.cond.L.Lock()
		s.Blockers--
		s.cond.Broadcast()
		s.cond.L.Unlock()
	}()
	defer sell.Dispose()
	if err := sell.PerformSell(log.Newf("Sell #%v", sell.GetKey()), s.m.receiveManager, interrupt); err != nil {
		s.LastError = fmt.Sprintf("Error performing sell (delaying next sell by 20s): %v", err)
		log.Println(s.LastError)
		s.cond.L.Lock()
		s.blockFor(20 * time.Second)
		s.cond.L.Unlock()
	} else {
		log.Printf("Returned from PerformSell successfully")
	}
}

func (t *Trade) awaitTransaction(log bitwrk.Logger) error {
	lastETag := ""
	for count := 1; ; count++ {
		if bid, etag, err := FetchBid(t.bidId, lastETag); err != nil {
			return fmt.Errorf("Error in FetchBid awaiting transaction: %v", err)
		} else if bid != nil {
			log.Printf("Bid: %#v ETag: %v lastETag: %v", *bid, etag, lastETag)
			t.bid = bid
			lastETag = etag
			if t.bid.State == bitwrk.Matched {
				t.txId = *t.bid.Transaction
				break
			} else if t.bid.State == bitwrk.Expired {
				return ErrBidExpired
			}
		}

		// Sleep for gradually longer durations
		time.Sleep(time.Duration(count) * 500 * time.Millisecond)
	}
	return nil
}

func NewWorkReceiver(log bitwrk.Logger,
	info string,
	receiveManager *ReceiveManager,
	storage cafs.FileStorage,
	key bitwrk.Tkey,
	handler WorkHandler) WorkReceiver {
	result := &endpointReceiver{
		endpoint:     receiveManager.NewEndpoint(info),
		storage:      storage,
		log:          log,
		handler:      handler,
		info:         info,
		encResultKey: key,
	}
	result.endpoint.SetHandler(func(w http.ResponseWriter, r *http.Request) {
		if err := result.handleRequest(w, r); err != nil {
			http.Error(w, err.Error(), http.StatusInternalServerError)
			log.Printf("Error in request: %v", err)
			result.Dispose()
		}
	})
	return result
}

func NewWorkReceiver(log bitwrk.Logger,
	info string,
	receiveManager *ReceiveManager,
	storage cafs.FileStorage,
	key bitwrk.Tkey,
	handler WorkHandler) WorkReceiver {
	result := &endpointReceiver{
		endpoint:     receiveManager.NewEndpoint(info),
		storage:      storage,
		log:          log,
		handler:      handler,
		info:         info,
		encResultKey: key,
	}
	handlerFunc := func(w http.ResponseWriter, r *http.Request) {
		if err := result.handleRequest(w, r); err != nil {
			http.Error(w, err.Error(), http.StatusInternalServerError)
			log.Printf("Error in request: %v", err)
			result.doDispose(fmt.Errorf("Error handling request from %v: %v", r.RemoteAddr, err))
		}
	}
	result.endpoint.SetHandler(withCompression(handlerFunc))
	return result
}

// Polls the transaction state in a separate go-routine. Returns on abort signal, or
// when the polled transaction expires.
func (t *Trade) pollTransaction(log bitwrk.Logger, abort <-chan bool) {
	defer func() {
		log.Printf("Transaction polling has stopped")
	}()

	for count := 1; ; count++ {
		select {
		case <-abort:
			log.Printf("Aborting transaction polling while transaction active")
			return
		default:
		}

		if tx, etag, err := FetchTx(t.txId, ""); err != nil {
			log.Printf("Error polling transaction: %v", err)
		} else if etag != t.txETag {
			t.condition.L.Lock()
			t.tx = tx
			t.txETag = etag
			expired := t.tx.State != bitwrk.StateActive
			t.condition.Broadcast()
			t.condition.L.Unlock()
			log.Printf("Tx change detected: phase=%v, expired=%v", t.tx.Phase, expired)
			if expired {
				break
			}
		}

		// Sleep for gradually longer durations
		time.Sleep(time.Duration(count) * 500 * time.Millisecond)
	}

	log.Printf("Transaction has expired.")
	// This is necessary so that the surrounding function call doesn't deadlock
	<-abort
}

func (a *SellActivity) HandleWork(log bitwrk.Logger, workFile cafs.File, buyerSecret bitwrk.Thash) (io.ReadCloser, error) {
	// Wait for buyer to establish
	active := true
	var workHash, workSecretHash *bitwrk.Thash
	log.Printf("Watching transaction state...")
	a.waitWhile(func() bool {
		active = a.tx.State == bitwrk.StateActive
		workHash, workSecretHash = a.tx.WorkHash, a.tx.WorkSecretHash
		log.Printf("  state: %v    phase: %v", a.tx.State, a.tx.Phase)
		return active && a.tx.Phase != bitwrk.PhaseTransmitting
	})

	if !active {
		return nil, fmt.Errorf("Transaction timed out waiting for buyer to establish")
	}

	// Verify work hash
	if *workHash != bitwrk.Thash(workFile.Key()) {
		return nil, fmt.Errorf("WorkHash and received data do not match")
	}

	if err := verifyBuyerSecret(workHash, workSecretHash, &buyerSecret); err != nil {
		return nil, err
	}

	log.Println("Got valid work data. Publishing buyer's secret.")
	if err := SendTxMessagePublishBuyerSecret(a.txId, a.identity, &buyerSecret); err != nil {
		return nil, fmt.Errorf("Error publishing buyer's secret: %v", err)
	}

	log.Println("Starting to work...")
	r, err := a.dispatchWork(log, workFile)
	if err != nil {
		log.Printf("Rejecting work because of error '%v'", err)
		if err := SendTxMessageRejectWork(a.txId, a.identity); err != nil {
			log.Printf("Rejecting work failed: %v", err)
		}
	}
	return r, err
}

func (a *BuyActivity) transmitWorkLinear(log bitwrk.Logger, client *http.Client) (io.ReadCloser, error) {
	// Send work to client
	pipeIn, pipeOut := io.Pipe()
	mwriter := multipart.NewWriter(pipeOut)

	// Write work file into pipe for HTTP request
	go func() {
		part, err := mwriter.CreateFormFile("work", "workfile.bin")
		if err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		work := a.workFile.Open()
		log.Printf("Sending work data to seller [%v].", *a.tx.WorkerURL)
		_, err = io.Copy(part, work)
		work.Close()
		if err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		log.Printf("Sending buyer's secret to seller.")
		err = mwriter.WriteField("buyersecret", a.buyerSecret.String())
		if err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		err = mwriter.Close()
		if err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		err = pipeOut.Close()
		if err != nil {
			pipeOut.CloseWithError(err)
			return
		}
		log.Printf("Work transmitted successfully.")
	}()

	return a.postToSeller(pipeIn, mwriter.FormDataContentType(), false, client)
}

func (t *Trade) waitForTransactionPhase(log bitwrk.Logger, phase bitwrk.TxPhase, viaPhases ...bitwrk.TxPhase) error {
	log.Printf("Waiting for transaction phase %v...", phase)

	if err := t.updateTransaction(log); err != nil {
		return err
	}

	var currentPhase bitwrk.TxPhase
	var currentState bitwrk.TxState
	t.waitWhile(func() bool {
		currentPhase = t.tx.Phase
		currentState = t.tx.State
		log.Printf("Phase: %v - State: %v", currentPhase, currentState)
		if currentState != bitwrk.StateActive {
			return false
		}
		if currentPhase == phase {
			return false
		}
		valid := false
		for _, via := range viaPhases {
			if currentPhase == via {
				valid = true
				break
			}
		}
		return valid
	})
	if currentState != bitwrk.StateActive {
		return ErrTxExpired
	}

	if currentPhase == phase {
		log.Printf("Phase %v reached.", phase)
		return nil
	}

	return ErrTxUnexpectedState
}