func (session *Session) getSingleFile() error { dumpcount := 0 xfer := session.tr rexmit := &(xfer.retransmit) /* negotiate the file request with the server */ if err := session.openTransfer(xfer.remoteFileName, xfer.localFileName); err != nil { fmt.Fprintln(os.Stderr, "File transfer request failed", err) return err } if err := session.openPort(); err != nil { fmt.Fprintln(os.Stderr, "Creation of data socket failed") return err } defer xfer.udpConnection.Close() rexmit.table = make([]uint32, DEFAULT_TABLE_SIZE) xfer.received = make([]byte, xfer.blockCount/8+2) xfer.ringBuffer = session.NewRingBuffer() ch := make(chan int) /* start up the disk I/O thread */ go session.disk_thread(ch) /* Finish initializing the retransmission object */ rexmit.tableSize = DEFAULT_TABLE_SIZE rexmit.indexMax = 0 /* we start by expecting block #1 */ xfer.nextBlock = 1 xfer.gaplessToBlock = 0 /*--------------------------- * START TIMING *---------------------------*/ xfer.stats = statistics{} xfer.stats.startUdpErrors = tsunami.Get_udp_in_errors() xfer.stats.thisUdpErrors = xfer.stats.startUdpErrors xfer.stats.startTime = time.Now() xfer.stats.thisTime = xfer.stats.startTime session.XsriptDataStart(xfer.stats.startTime) /* until we break out of the transfer */ local_datagram := make([]byte, 6+session.param.blockSize) for { /* try to receive a datagram */ _, err := xfer.udpConnection.Read(local_datagram) if err != nil { fmt.Fprintln(os.Stderr, "UDP data transmission error") fmt.Println("Apparently frozen transfer, trying to do retransmit request") if err = session.repeatRetransmit(); err != nil { /* repeat our requests */ fmt.Fprintln(os.Stderr, "Repeat of retransmission requests failed") return err } } /* retrieve the block number and block type */ this_block := binary.BigEndian.Uint32(local_datagram[:4]) // in range of 1..xfer.block_count this_type := binary.BigEndian.Uint16(local_datagram[4:6]) // TS_BLOCK_ORIGINAL etc /* keep statistics on received blocks */ xfer.stats.totalBlocks++ if this_type != tsunami.TS_BLOCK_RETRANSMISSION { xfer.stats.thisFlowOriginals++ } else { xfer.stats.thisFlowRetransmitteds++ xfer.stats.totalRecvdRetransmits++ } /* main transfer control logic */ if !xfer.ringBuffer.isFull() { /* don't let disk-I/O freeze stop feedback of stats to server */ if session.gotBlock(this_block) != 0 || this_type == tsunami.TS_BLOCK_TERMINATE || xfer.restartPending { /* insert new blocks into disk write ringbuffer */ if session.gotBlock(this_block) != 0 { /* reserve ring space, copy the data in, confirm the reservation */ datagram, err := xfer.ringBuffer.reserve() if err != nil { fmt.Fprintln(os.Stderr, "Error in accepting block reserve") return err } copy(datagram, local_datagram) if err = xfer.ringBuffer.confirm(); err != nil { fmt.Fprintln(os.Stderr, "Error in accepting block") return err } /* mark the block as received */ xfer.received[this_block/8] |= (1 << (this_block % 8)) if xfer.blocksLeft > 0 { xfer.blocksLeft-- } else { fmt.Printf("Oops! Negative-going blocksLeft count at block: type=%c this=%u final=%u left=%u\n", this_type, this_block, xfer.blockCount, xfer.blocksLeft) } } /* transmit restart: avoid re-triggering on blocks still down the wire before server reacts */ if (xfer.restartPending) && (this_type != tsunami.TS_BLOCK_TERMINATE) { if (this_block > xfer.restartLastIndex) && (this_block <= xfer.restartWireClearIndex) { goto send_stats } } /* queue any retransmits we need */ if this_block > xfer.nextBlock { /* lossy transfer mode */ if !session.param.lossless { if session.param.losswindow_ms == 0 { /* lossy transfer, no retransmits */ xfer.gaplessToBlock = this_block } else { /* semi-lossy transfer, purge data past specified approximate time window */ var path_capability float64 path_capability = 0.8 * (xfer.stats.thisTransmitRate + xfer.stats.thisRetransmitRate) // reduced effective Mbit/s rate path_capability *= 0.001 * float64(session.param.losswindow_ms) // MBit inside window, round-trip user estimated in losswindow_ms! min := 1024 * 1024 * uint32(path_capability) / (8 * session.param.blockSize) // # of blocks inside window if min > this_block-xfer.gaplessToBlock { min = this_block - xfer.gaplessToBlock } earliest_block := this_block - min if err = session.requestRetransmitBlocks(earliest_block, this_block); err != nil { return err } // hop over the missing section xfer.nextBlock = earliest_block xfer.gaplessToBlock = earliest_block } /* lossless transfer mode, request all missing data to be resent */ } else { if err = session.requestRetransmitBlocks(xfer.nextBlock, this_block); err != nil { return err } } } //if(missing blocks) /* advance the index of the gapless section going from start block to highest block */ for session.gotBlock(xfer.gaplessToBlock+1) != 0 && xfer.gaplessToBlock < xfer.blockCount { xfer.gaplessToBlock++ } /* if this is an orignal, we expect to receive the successor to this block next */ /* transmit restart note: these resent blocks are labeled original as well */ if this_type == tsunami.TS_BLOCK_ORIGINAL { xfer.nextBlock = this_block + 1 } /* transmit restart: already got out of the missing blocks range? */ if xfer.restartPending && (xfer.nextBlock >= xfer.restartLastIndex) { xfer.restartPending = false } /* are we at the end of the transmission? */ if this_type == tsunami.TS_BLOCK_TERMINATE { // fmt.Fprintf(os.Stderr, "Got end block: blk %u, final blk %u, left blks %u, tail %u, head %u\n", // this_block, xfer.blockCount, xfer.blocksLeft, xfer.gaplessToBlock, xfer.nextBlock) /* got all blocks by now */ if xfer.blocksLeft == 0 { break } else if !session.param.lossless { if rexmit.indexMax == 0 && !xfer.restartPending { break } } /* add possible still missing blocks to retransmit list */ if err = session.requestRetransmitBlocks(xfer.gaplessToBlock+1, xfer.blockCount); err != nil { return err } /* send the retransmit request list again */ session.repeatRetransmit() } } //if(not a duplicate block) send_stats: /* repeat our server feedback and requests if it's time */ if xfer.stats.totalBlocks%50 == 0 { /* if it's been at least 350ms */ if tsunami.Get_usec_since(xfer.stats.thisTime) > tsunami.UPDATE_PERIOD { /* repeat our retransmission requests */ if err = session.repeatRetransmit(); err != nil { fmt.Fprintln(os.Stderr, "Repeat of retransmission requests failed") return err } /* send and show our current statistics */ session.updateStats() /* progress blockmap (DEBUG) */ if session.param.blockDump { postfix := fmt.Sprintf(".bmap%d", dumpcount) dumpcount++ xfer.dumpBlockmap(postfix) } } } } /* Transfer of the file completes here*/ fmt.Println("Transfer complete. Flushing to disk and signaling server to stop...") /*--------------------------- * STOP TIMING *---------------------------*/ /* tell the server to quit transmitting */ if err = session.requestStop(); err != nil { fmt.Fprintln(os.Stderr, "Could not request end of transfer") return err } /* add a stop block to the ring buffer */ datagram, err := xfer.ringBuffer.reserve() //disk read block index 0 stop if err == nil { datagram[0] = 0 datagram[1] = 0 datagram[2] = 0 datagram[3] = 0 } if err = xfer.ringBuffer.confirm(); err != nil { fmt.Fprintln(os.Stderr, "Error in terminating disk thread", err) } /* wait for the disk thread to die */ flag := <-ch if flag == -2 { fmt.Fprintln(os.Stderr, "Disk thread terminated with error") } /*------------------------------------ * MORE TRUE POINT TO STOP TIMING ;-) *-----------------------------------*/ // time here would contain the additional delays from the // local disk flush and server xfer shutdown - include or omit? /* get finishing time */ xfer.stats.stopTime = time.Now() delta := tsunami.Get_usec_since(xfer.stats.startTime) /* count the truly lost blocks from the 'received' bitmap table */ xfer.stats.totalLost = 0 var block uint32 for block = 1; block <= xfer.blockCount; block++ { if session.gotBlock(block) == 0 { xfer.stats.totalLost++ } } session.displayResult(delta) session.XsriptDataStop(xfer.stats.stopTime) session.XsriptClose(uint64(delta)) /* dump the received packet bitfield to a file, with added filename prefix ".blockmap" */ if session.param.blockDump { xfer.dumpBlockmap(".blockmap") } /* close our open files */ if xfer.localFile != nil { xfer.localFile.Close() xfer.localFile = nil } /* deallocate memory */ // xfer.ringBuffer = nil // if rexmit.table != nil { // rexmit.table = nil // } // if xfer.received != nil { // xfer.received = nil // } /* update the target rate */ if session.param.rateAdjust { session.param.targetRate = uint32(1.15 * 1e6 * (8.0 * int64(xfer.fileSize) / delta * 1e6)) fmt.Printf("Adjusting target rate to %d Mbps for next transfer.\n", (int)(session.param.targetRate/1e6)) } } return nil }
/*------------------------------------------------------------------------ * int update_stats(session_t *session); * * This routine must be called every interval to update the statistics * for the progress of the ongoing file transfer. Returns 0 on success * and non-zero on failure. (There is not currently any way to fail.) *------------------------------------------------------------------------*/ func (s *Session) updateStats() { now_epoch := time.Now() /* the current Unix epoch */ var delta int64 /* time delta since last statistics update (usec) */ var delta_total int64 /* time delta since start of transmission (usec) */ var temp int64 /* temporary value for building the elapsed time */ var data_total float64 /* the total amount of data transferred (bytes) */ var data_this float64 /* the amount of data since last stat time */ var data_this_rexmit float64 /* the amount of data in received retransmissions */ // var data_this_goodpt float64 /* the amount of data as non-lost packets */ var retransmits_fraction float64 /* how many retransmit requests there were vs received blocks */ retransmission := make([]tsunami.Retransmission, 1) stats := &s.tr.stats /* find the total time elapsed */ delta = tsunami.Get_usec_since(stats.thisTime) temp = tsunami.Get_usec_since(stats.startTime) milliseconds := (temp % 1000000) / 1000 temp /= 1000000 seconds := temp % 60 temp /= 60 minutes := temp % 60 temp /= 60 hours := temp d_seconds := delta / 1e6 d_seconds_total := delta_total / 1e6 /* find the amount of data transferred (bytes) */ data_total = float64(s.param.blockSize) * float64(stats.totalBlocks) data_this = float64(s.param.blockSize) * float64(stats.totalBlocks-stats.thisBlocks) data_this_rexmit = float64(s.param.blockSize) * float64(stats.thisFlowRetransmitteds) // data_this_goodpt = float64(s.param.blockSize) * float64(stats.thisFlowOriginals) /* get the current UDP receive error count reported by the operating system */ stats.thisUdpErrors = tsunami.Get_udp_in_errors() /* precalculate some fractions */ retransmits_fraction = float64(stats.thisRetransmits) / (1.0 + float64(stats.thisRetransmits+stats.totalBlocks-stats.thisBlocks)) ringfill_fraction := float64(s.tr.ringBuffer.countData) / MAX_BLOCKS_QUEUED total_retransmits_fraction := float64(stats.totalRetransmits) / float64(stats.totalRetransmits+stats.totalBlocks) /* update the rate statistics */ // incoming transmit rate R = goodput R (Mbit/s) + retransmit R (Mbit/s) stats.thisTransmitRate = 8.0 * data_this / float64(d_seconds*u_mega) stats.thisRetransmitRate = 8.0 * data_this_rexmit / float64(d_seconds*u_mega) data_total_rate := 8.0 * data_total / float64(d_seconds_total*u_mega) fb := float64(s.param.history) / 100.0 // feedback ff := 1.0 - fb // feedforward // IIR filter rate R stats.transmitRate = fb*stats.transmitRate + ff*stats.thisRetransmitRate // IIR filtered composite error and loss, some sort of knee function stats.errorRate = fb*stats.errorRate + ff*500*100*(retransmits_fraction+ringfill_fraction) /* send the current error rate information to the server */ retransmission[0].RequestType = tsunami.REQUEST_ERROR_RATE retransmission[0].ErrorRate = uint32(s.tr.stats.errorRate) _, err := s.connection.Write(tsunami.Retransmissions(retransmission).Bytes()) if err != nil { fmt.Fprintln(os.Stderr, "Could not send error rate information", err) return } /* build the stats string */ statsFlags := s.statsFlags() //matlab // format := "%02d\t%02d\t%02d\t%03d\t%4u\t%6.2f\t%6.1f\t%5.1f\t%7u\t%6.1f\t%6.1f\t%5.1f\t%5d\t%5d\t%7u\t%8u\t%8Lu\t%s\n" format := "%02d:%02d:%02d.%03d %4u %6.2fM %6.1fMbps %5.1f%% %7u %6.1fG %6.1fMbps %5.1f%% %5d %5d %7u %8u %8u %s\n" /* print to the transcript if the user wants */ statusLine := fmt.Sprintf(format, hours, minutes, seconds, milliseconds, stats.totalBlocks-stats.thisBlocks, stats.thisRetransmitRate, stats.thisTransmitRate, 100.0*retransmits_fraction, s.tr.stats.totalBlocks, data_total/float64(u_giga), data_total_rate, 100.0*total_retransmits_fraction, s.tr.retransmit.indexMax, s.tr.ringBuffer.countData, s.tr.blocksLeft, stats.thisRetransmits, uint64(stats.thisUdpErrors-stats.startUdpErrors), statsFlags) /* give the user a show if they want it */ if s.param.verbose { /* screen mode */ if s.param.outputMode == SCREEN_MODE { fmt.Printf("\033[2J\033[H") fmt.Printf("Current time: %s\n", now_epoch.Format(time.RFC3339)) fmt.Printf("Elapsed time: %02d:%02d:%02d.%03d\n\n", hours, minutes, seconds, milliseconds) fmt.Printf("Last interval\n--------------------------------------------------\n") fmt.Printf("Blocks count: %u\n", stats.totalBlocks-stats.thisBlocks) fmt.Printf("Data transferred: %0.2f GB\n", data_this/float64(u_giga)) fmt.Printf("Transfer rate: %0.2f Mbps\n", stats.thisTransmitRate) fmt.Printf("Retransmissions: %u (%0.2f%%)\n\n", stats.thisRetransmits, 100.0*retransmits_fraction) fmt.Printf("Cumulative\n--------------------------------------------------\n") fmt.Printf("Blocks count: %u\n", s.tr.stats.totalBlocks) fmt.Printf("Data transferred: %0.2f GB\n", data_total/float64(u_giga)) fmt.Printf("Transfer rate: %0.2f Mbps\n", data_total_rate) fmt.Printf("Retransmissions: %u (%0.2f%%)\n", stats.totalRetransmits, 100.0*total_retransmits_fraction) fmt.Printf("Flags : %s\n\n", statsFlags) fmt.Printf("OS UDP rx errors: %u\n", uint64(stats.thisUdpErrors-stats.startUdpErrors)) /* line mode */ } else { // s.iteration++ // if s.iteration%23 == 0 { // fmt.Printf(" last_interval transfer_total buffers transfer_remaining OS UDP\n") // fmt.Printf("time blk data rate rexmit blk data rate rexmit queue ring blk rt_len err \n") // } fmt.Printf("%s", statusLine) } os.Stdout.Sync() } s.XsriptDataLog(statusLine) /* reset the statistics for the next interval */ stats.thisBlocks = stats.totalBlocks stats.thisRetransmits = 0 stats.thisFlowOriginals = 0 stats.thisFlowRetransmitteds = 0 stats.thisTime = time.Now() }