/** * Calculates and returns the loss event rate * TODO: add history discounting */ double loss_event_rate(struct group_list_t *group) { double weights[8] = { 1.0, 1.0, 1.0, 1.0, 0.8, 0.6, 0.4, 0.2 }; double loss_sum_cur, loss_sum_no_cur, weight_sum; int i; if (group->slowstart) { return 0.0; } loss_sum_cur = 0; loss_sum_no_cur = 0; weight_sum = 0; for (i = 0; i < 8; i++) { glog5(group, "loss_events[%d].len=%d", i, group->loss_events[i].len); if (group->loss_events[i].len != 0) { loss_sum_cur += group->loss_events[i].len * weights[i]; weight_sum += weights[i]; } } for (i = 1; i < 9; i++) { if (group->loss_events[i].len == 0) break; loss_sum_no_cur += group->loss_events[i].len * weights[i - 1]; } glog5(group, "cur_sum=%f, cur_no_sum=%f, weight_sum=%f", loss_sum_cur, loss_sum_no_cur, weight_sum); // Return inverse of larger average if (loss_sum_no_cur > loss_sum_cur) { return weight_sum / loss_sum_no_cur; } else { return weight_sum / loss_sum_cur; } }
/** * Returns the current congestion control rate in bytes / second. * As specified in RFC 4654 */ unsigned current_cc_rate(struct group_list_t *group) { double p, rtt; int i, bytes, thresh; if (group->rtt != 0.0) { rtt = group->rtt; } else { rtt = group->grtt; } p = loss_event_rate(group); if (p == 0.0) { thresh = (int)(group->grtt * 1000000 * 4); bytes = 0; i = group->max_txseq; while ((i != group->start_txseq) && (diff_usec(group->loss_history[group->max_txseq].t, group->loss_history[i].t) < thresh)) { bytes += group->loss_history[i--].size; } return (unsigned)(2.0 * bytes / (4.0 * group->grtt)); } else { glog5(group, "getting cc rate, p=%f, rtt=%f", p, rtt); return (unsigned)(group->datapacketsize / (rtt * (sqrt(p * 2.0 / 3.0) + (12 * sqrt(p * 3.0 / 8.0) * p * (1 + (32 * p * p)))))); } }
/** * Sets the timeout time for a given group list member */ void set_timeout(struct pr_group_list_t *group, int pending_reset, int rescale) { int pending, i; if (group->phase == PR_PHASE_READY) { if (!rescale) { gettimeofday(&group->start_phase_timeout_time, NULL); } group->phase_timeout_time = group->start_phase_timeout_time; add_timeval_d(&group->phase_timeout_time, 2 * group->grtt); } glog5(group, "set timeout: pending_reset=%d", pending_reset); for (pending = 0, i = 0; (i < MAX_PEND) && !pending; i++) { if (group->pending[i].msg != 0) { glog5(group, "set timeout: found pending %s", func_name(group->pending[i].msg)); pending = group->pending[i].msg; } } if (pending) { if (pending_reset) { if (!rescale) { gettimeofday(&group->start_timeout_time, NULL); } group->timeout_time = group->start_timeout_time; add_timeval_d(&group->timeout_time, 1 * group->grtt); } } else { if (!rescale) { gettimeofday(&group->start_timeout_time, NULL); } group->timeout_time = group->start_timeout_time; if (group->robust * group->grtt < 1.0) { add_timeval_d(&group->timeout_time, 1.0); } else { add_timeval_d(&group->timeout_time, group->robust * group->grtt); } } }
/** * Gets the current timeout value to use for the main loop * * First check to see if any active groups have an expired timeout, and * handle that timeout. Once all expired timeouts have been handled, find * the active group with the earliest timeout and return the time until that * timeout. If there are no active groups, return NULL. */ struct timeval *getrecenttimeout(void) { static struct timeval tv = {0,0}; struct timeval current_timestamp, min_timestamp; int i, found_timeout, done, sent_naks; struct group_list_t *group; unsigned int section, nak_count; unsigned char *naks; gettimeofday(¤t_timestamp, NULL); done = 0; while (!done) { found_timeout = 0; done = 1; for (i = 0; i < MAXLIST; i++) { group = &group_list[i]; if (group->group_id != 0) { if (cmptimestamp(current_timestamp, group->timeout_time) >= 0) { switch (group->phase) { case PHASE_REGISTERED: send_register(group); break; case PHASE_RECEIVING: case PHASE_MIDGROUP: glog1(group, "Transfer timed out"); send_abort(group, "Transfer timed out"); break; case PHASE_COMPLETE: send_complete(group, 0); break; } done = 0; } else if ((!found_timeout) || (cmptimestamp(group->timeout_time, min_timestamp) < 0)) { glog5(group, "found min timeout time: %d:%06d", group->timeout_time.tv_sec, group->timeout_time.tv_usec); min_timestamp = group->timeout_time; found_timeout = 1; } // Check for a NAK timeout for sending a STATUS or COMPLETE if ((group->fileinfo.nak_time.tv_sec != 0) && cmptimestamp(current_timestamp, group->fileinfo.nak_time) >= 0) { group->fileinfo.nak_time.tv_sec = 0; group->fileinfo.nak_time.tv_usec = 0; // Send NAKs sent_naks = 0; retry_naks: for (section = group->fileinfo.nak_section_first; section < group->fileinfo.nak_section_last; section++) { naks = NULL; nak_count = get_naks(group, section, &naks); glog3(group, "read %d NAKs for section %d", nak_count, section); if (nak_count > 0) { send_status(group, section, naks, nak_count); sent_naks = 1; } free(naks); naks = NULL; } if (file_done(group, 1)) { glog2(group, "File transfer complete"); send_complete(group, 0); file_cleanup(group, 0); } else if (group->fileinfo.got_done && !sent_naks) { // We didn't send any NAKs since the last time // but the server is asking for some, // so check all prior sections group->fileinfo.nak_section_last = group->fileinfo.nak_section_first; group->fileinfo.nak_section_first = 0; group->fileinfo.got_done = 0; goto retry_naks; } } else if ((group->fileinfo.nak_time.tv_sec != 0) && ((!found_timeout) || (cmptimestamp(group->fileinfo.nak_time, min_timestamp) < 0))) { glog5(group, "found min nak time: %d:%06d", group->fileinfo.nak_time.tv_sec, group->fileinfo.nak_time.tv_usec); min_timestamp = group->fileinfo.nak_time; found_timeout = 1; } // Check congestion control feedback timer if (!group->isclr) { if ((group->cc_time.tv_sec != 0) && (cmptimestamp(current_timestamp, group->cc_time) >= 0)) { send_cc_ack(group); } else if ((group->cc_time.tv_sec != 0) && ((!found_timeout) || (cmptimestamp(group->cc_time, min_timestamp) < 0))) { glog5(group, "found min CC time: %d:%06d", group->cc_time.tv_sec, group->cc_time.tv_usec); min_timestamp = group->cc_time; found_timeout = 1; } } } } // Check timeout for proxy key request if (has_proxy && (proxy_pubkey.key == 0)) { if (cmptimestamp(current_timestamp, next_keyreq_time) >= 0) { send_key_req(); done = 0; } else if ((!found_timeout) || (cmptimestamp(next_keyreq_time, min_timestamp) < 0)) { min_timestamp = next_keyreq_time; found_timeout = 1; } } // Check timeout for sending heartbeat if (hbhost_count) { if (cmptimestamp(current_timestamp, next_hb_time) >= 0) { send_hb_request(listener, hb_hosts, hbhost_count, &next_hb_time, hb_interval, uid); done = 0; } else if ((!found_timeout) || (cmptimestamp(next_hb_time, min_timestamp) < 0)) { min_timestamp = next_hb_time; found_timeout = 1; } } } if (found_timeout) { tv = diff_timeval(min_timestamp, current_timestamp); return &tv; } else { return NULL; } }
/** * This is the main message reading loop. Messages are read, validated, * decrypted if necessary, then passed to the appropriate routine for handling. */ void mainloop(void) { struct uftp_h *header; struct group_list_t *group; unsigned char *buf, *decrypted, *message; char rxname[INET6_ADDRSTRLEN]; unsigned int decryptlen, meslen; int packetlen, rval, i, ecn; uint8_t version, *func, tos; uint16_t txseq; union sockaddr_u src; struct timeval *tv, rxtime; double new_grtt; log2(0, 0, 0, "%s", VERSIONSTR); for (i = 0; i < key_count; i++) { if (privkey_type[i] == KEYBLOB_RSA) { log2(0, 0, 0, "Loaded %d bit RSA key with fingerprint %s", RSA_keylen(privkey[i].rsa) * 8, print_key_fingerprint(privkey[i], KEYBLOB_RSA)); } else { log2(0, 0, 0, "Loaded ECDSA key with curve %s and fingerprint %s", curve_name(get_EC_curve(privkey[i].ec)), print_key_fingerprint(privkey[i], KEYBLOB_EC)); } } buf = safe_calloc(MAXMTU, 1); decrypted = safe_calloc(MAXMTU, 1); header = (struct uftp_h *)buf; while (1) { tv = getrecenttimeout(); if (tv) { log5(0, 0, 0, "read timeout: %d.%06d", tv->tv_sec, tv->tv_usec); } if (read_packet(listener, &src, buf, &packetlen, MAXMTU, tv, &tos) <= 0) { continue; } gettimeofday(&rxtime, NULL); if ((rval = getnameinfo((struct sockaddr *)&src, family_len(src), rxname, sizeof(rxname), NULL, 0, NI_NUMERICHOST)) != 0) { log1(0, 0, 0, "getnameinfo failed: %s", gai_strerror(rval)); } if (header->version == UFTP_VER_NUM) { version = header->version; group = find_group(ntohl(header->group_id), header->group_inst); } else { log1(0, 0, 0, "Invalid message from %s: not uftp packet " "or invalid version", rxname); continue; } if (packetlen < sizeof(struct uftp_h) + 4) { log1(0, 0, 0, "Invalid packet size from %s: %d", rxname, packetlen); continue; } txseq = htons(header->seq); // A KEY_INFO or ABORT could come from a proxy, so don't check the seq // TODO: need to account for these in the loss history if ((group != NULL) && (header->func != KEYINFO) && (header->func != ABORT)) { if ((int16_t)(group->max_txseq - txseq) > MAXMISORDER) { glog3(group, "seq out of range, dropping"); continue; } if (group->cc_type != CC_NONE) { ecn = ((tos & 0x3) == 3); update_loss_history(group, txseq, packetlen, ecn); } else if ((int16_t)(txseq - group->max_txseq) > 0) { group->max_txseq = txseq; } } if ((header->func == ENCRYPTED) && (group != NULL) && (group->keytype != KEY_NONE)) { if (group->phase == PHASE_REGISTERED) { glog1(group, "Got encrypted packet from %s " "but keys not established", rxname); } if (!validate_and_decrypt(buf, packetlen, &decrypted, &decryptlen, group->keytype, group->groupkey, group->groupsalt, group->ivlen, group->hashtype, group->grouphmackey, group->hmaclen, group->sigtype, group->keyextype, group->server_pubkey, group->server_pubkeylen)) { glog1(group, "Rejecting message from %s: " "decrypt/validate failed", rxname); continue; } func = (uint8_t *)decrypted; message = decrypted; meslen = decryptlen; } else { if ((group != NULL) && (group->keytype != KEY_NONE) && ((header->func == FILEINFO) || (header->func == FILESEG) || (header->func == DONE) || (header->func == DONE_CONF) || ((header->func == ABORT) && (group->phase != PHASE_REGISTERED)))) { glog1(group, "Rejecting %s message from %s: not encrypted", func_name(header->func), rxname); continue; } func = (uint8_t *)&header->func; message = buf + sizeof(struct uftp_h); meslen = packetlen - sizeof(struct uftp_h); } if (group != NULL) { new_grtt = unquantize_grtt(header->grtt); if (fabs(new_grtt - group->grtt) > 0.001) { group->grtt = new_grtt; set_timeout(group, 1); } group->gsize = unquantize_gsize(header->gsize); glog5(group, "grtt: %.3f", group->grtt); } if (header->func == PROXY_KEY) { handle_proxy_key(&src, message, meslen); continue; } if (header->func == HB_RESP) { handle_hb_response(listener, &src, message, meslen, hb_hosts, hbhost_count, privkey[0], privkey_type[0], uid); continue; } if (header->func == ANNOUNCE) { // Ignore any ANNOUNCE for a group we're already handling if (group == NULL) { handle_announce(&src, buf, packetlen, rxtime); } else if (group->phase == PHASE_MIDGROUP) { // Make sure we don't time out while waiting for other // clients to register with the server. set_timeout(group, 0); } } else { if (group == NULL) { // group / file ID not in list continue; } if (group->version != version) { glog1(group, "Version mismatch"); continue; } if (group->src_id != header->src_id) { glog1(group, "Source ID mismatch"); continue; } if (*func == ABORT) { handle_abort(group, message, meslen); continue; } switch (group->phase) { case PHASE_REGISTERED: if (group->keytype != KEY_NONE) { if (*func == KEYINFO) { handle_keyinfo(group, message, meslen, header->src_id); } else { glog1(group, "Expected KEYINFO, got %s", func_name(*func)); } } else if (group->keytype == KEY_NONE) { if (*func == REG_CONF) { handle_regconf(group, message, meslen); } else if (*func == FILEINFO) { handle_fileinfo(group, message, meslen, rxtime); } else { glog1(group, "Expected REG_CONF, got %s", func_name(*func)); } } break; case PHASE_MIDGROUP: if (*func == FILEINFO) { handle_fileinfo(group, message, meslen, rxtime); } else if (*func == KEYINFO) { handle_keyinfo(group, message, meslen, header->src_id); } else if (*func == DONE) { handle_done(group, message, meslen); } else { // Other clients may be still getting earlier files or // setting up, so silently ignore anything unexpected // and reset the timeout. set_timeout(group, 0); } break; case PHASE_RECEIVING: if (*func == FILEINFO) { handle_fileinfo(group, message, meslen, rxtime); } else if (*func == FILESEG) { handle_fileseg(group, message, meslen, txseq); } else if (*func == DONE) { handle_done(group, message, meslen); } else if (*func == CONG_CTRL) { handle_cong_ctrl(group, message, meslen, rxtime); } break; case PHASE_COMPLETE: if (*func == DONE_CONF) { handle_done_conf(group, message, meslen); } break; } } } }
/** * Reads an expected FILESEG and writes it to the proper place in the file */ void handle_fileseg(struct group_list_t *group, const unsigned char *message, unsigned meslen, uint16_t txseq) { const struct fileseg_h *fileseg; const struct tfmcc_data_info_he *tfmcc; const unsigned char *data; const uint8_t *he; int datalen, section, cache_offset, status_idx; uint32_t seq, i; unsigned extlen; if (group->fileinfo.ftype != FTYPE_REG) { glog2(group, "Rejecting FILESEG: not a regular file"); return; } fileseg = (const struct fileseg_h *)message; data = message + (fileseg->hlen * 4); datalen = meslen - (fileseg->hlen * 4); if ((meslen < (fileseg->hlen * 4U)) || ((fileseg->hlen * 4U) < sizeof(struct fileseg_h))) { glog2(group, "Rejecting FILESEG: invalid message size"); return; } if (ntohs(fileseg->file_id) != group->file_id) { glog2(group, "Rejecting FILESEG: got incorrect file_id %04X", ntohs(fileseg->file_id)); return; } tfmcc = NULL; if (fileseg->hlen * 4U > sizeof(struct fileseg_h)) { he = (const uint8_t *)fileseg + sizeof(struct fileseg_h); if (*he == EXT_TFMCC_DATA_INFO) { tfmcc = (const struct tfmcc_data_info_he *)he; extlen = tfmcc->extlen * 4U; if ((extlen > (fileseg->hlen * 4U) - sizeof(struct fileseg_h)) || extlen < sizeof(struct tfmcc_data_info_he)) { glog2(group, "Rejecting FILESEG: invalid extension size"); return; } } } section = ntohs(fileseg->section); if (section >= group->fileinfo.big_sections) { seq = (group->fileinfo.big_sections * group->fileinfo.secsize_big) + ((section - group->fileinfo.big_sections) * group->fileinfo.secsize_small) + ntohs(fileseg->sec_block); } else { seq = (section * group->fileinfo.secsize_big) + ntohs(fileseg->sec_block); } if ((datalen != group->blocksize) && (seq != group->fileinfo.blocks - 1)) { glog2(group, "Rejecting FILESEG: invalid data size %d", datalen); return; } if (log_level >= 5) { glog5(group, "Got packet %d", seq); } else if (log_level == 4) { if (seq != group->fileinfo.last_block + 1) { glog4(group, "Got packet %d, last was %d", seq, group->fileinfo.last_block); } } if ((group->cc_type == CC_TFMCC) && tfmcc) { handle_tfmcc_data_info(group, tfmcc); } group->fileinfo.got_data = 1; group->fileinfo.last_block = seq; if (txseq == group->max_txseq) { if ((section > group->fileinfo.last_section) && (group->fileinfo.nak_time.tv_sec == 0)) { // Start timer to send NAKs gettimeofday(&group->fileinfo.nak_time, NULL); add_timeval_d(&group->fileinfo.nak_time, 1 * group->grtt); group->fileinfo.nak_section_first = group->fileinfo.last_section; group->fileinfo.nak_section_last = section; group->fileinfo.got_done = 0; glog3(group, "New section, set NAK timer for sections %d - %d", group->fileinfo.nak_section_first, group->fileinfo.nak_section_last); } group->fileinfo.last_section = section; } if (group->fileinfo.naklist[seq]) { if ((seq >= group->fileinfo.cache_start) && (seq <= group->fileinfo.cache_end + MAXMISORDER)) { cache_offset=(seq - group->fileinfo.cache_start) * group->blocksize; if (seq > group->fileinfo.cache_end) { if ((cache_offset + datalen) > cache_len) { glog4(group, "Disk cache full, flushing"); if (!flush_disk_cache(group)) { return; } cache_offset = (seq - group->fileinfo.cache_start) * group->blocksize; } else { for (i = group->fileinfo.cache_end; i <= seq; i++) { if (!group->fileinfo.naklist[i]) { glog3(group, "Cache gap seq %d " "already received, flushing", i); if (!flush_disk_cache(group)) { return; } group->fileinfo.cache_start = seq; cache_offset = 0; break; } } group->fileinfo.cache_end = seq; } } } else { if (group->fileinfo.cache_len != 0) { glog3(group, "Seq %d out of cache range, flushing", seq); if (!flush_disk_cache(group)) { return; } } cache_offset = 0; group->fileinfo.cache_start = seq; group->fileinfo.cache_end = seq; } group->fileinfo.cache_len = ((group->fileinfo.cache_end - group->fileinfo.cache_start) * group->blocksize) + datalen; status_idx = seq - group->fileinfo.cache_start; if (group->fileinfo.cache_len > cache_len) { glog0(group, "Cache overrun: " "current cache len = %d, status_idx = %d", group->fileinfo.cache_len, status_idx); } group->fileinfo.cache_status[status_idx] = 1; memcpy(&group->fileinfo.cache[cache_offset], data, datalen); } set_timeout(group, 0); }
/** * Creates all directories in the given file's path, removing existing files. * Returns 1 on success, 0 on failure */ int create_path_to_file(struct group_list_t *group, const char *filename) { char *dir, *base; stat_struct statbuf; int rval; split_path(filename, &dir, &base); if (!dir) { glog1(group, "Invalid path element %s", filename); rval = 0; goto end; } #ifdef WINDOWS if ((base == NULL) || ((strlen(dir) == 2) && (dir[1] == ':'))) { #else if ((!strcmp(dir, ".")) || (!strcmp(dir, "/"))) { #endif // At top level directory, so stop recursion rval = 1; goto end; } if (lstat_func(dir, &statbuf) != -1) { if (!S_ISDIR(statbuf.st_mode)) { if (unlink(dir) == -1) { gsyserror(group, "Failed to delete path element %s", dir); rval = 0; goto end; } if (mkdir(dir, 0755) == -1) { gsyserror(group, "Failed to create path element %s", dir); rval = 0; goto end; } } } else { // If the file's directory does not exist, recurse first to make sure // all parent directories exist if (!create_path_to_file(group, dir)) { rval = 0; goto end; } if (mkdir(dir, 0755) == -1) { gsyserror(group, "Failed to create path element %s", dir); rval = 0; goto end; } } rval = 1; end: free(dir); free(base); return rval; } void new_loss_event(struct group_list_t *group, uint16_t txseq) { uint32_t seq_long; uint16_t count; int bytes, avgbytes, rate, grtt_usec; glog4(group, "Seq %d starts new loss event", txseq); // Found a new loss event if (txseq < group->max_txseq - MAXMISORDER) { glog5(group, "wrap check, i=%u, maxseq=%u", txseq, group->max_txseq); seq_long = ((group->seq_wrap - 1) << 16) | txseq; } else { seq_long = (group->seq_wrap << 16) | txseq; } if (group->slowstart) { group->slowstart = 0; // Initialize loss history count = group->max_txseq; bytes = 0; grtt_usec = (int)(group->grtt * 1000000); while ((count != group->start_txseq) && (diff_usec(group->loss_history[txseq].t, group->loss_history[count].t) < grtt_usec)) { bytes += group->loss_history[count--].size; } rate = (int)(bytes / group->grtt); glog4(group, "End slowstart, calculated rate = %d", rate); avgbytes= bytes / ((int16_t)(group->max_txseq - count)); group->loss_events[0].len = (int)(0 + pow( (rate * ((group->rtt != 0) ? group->rtt : group->grtt)) / (sqrt(1.5) * 8 * avgbytes), 2)); glog4(group, "Calculated prior event len = %d (rtt=%f, avgbytes=%d)", group->loss_events[0].len, group->rtt,avgbytes); } else { group->loss_events[0].len = seq_long - group->loss_events[0].start_seq; glog4(group, "Prior event length = %d (i=%u, start=%u)", group->loss_events[0].len, seq_long, group->loss_events[0].start_seq); } memmove(&group->loss_events[1], &group->loss_events[0], sizeof(struct loss_event_t) * 8); group->loss_events[0].start_seq = seq_long; group->loss_events[0].len = 0; group->loss_events[0].t = group->loss_history[txseq].t; }
/** * Updates the group's loss history * * Packets older than MAXMISORDER sequence numbers don't change the loss * history, and packets aren't considered lost unless the sequence number is * more than MAXMISORDER sequence numbers old. Works under the assumption * that no more than 32K packets in a row get lost. */ void update_loss_history(struct group_list_t *group, uint16_t txseq, int size, int ecn) { uint16_t i; int tdiff, grtt_usec; struct timeval tvdiff; group->loss_history[txseq].found = 1; gettimeofday(&group->loss_history[txseq].t, NULL); if (group->multi.ss.ss_family == AF_INET6) { group->loss_history[txseq].size = size + 8 + 40; } else { group->loss_history[txseq].size = size + 8 + 20; } if ((int16_t)(txseq - group->max_txseq) > 0) { glog4(group, "Got seq %d, max was %d", txseq, group->max_txseq); grtt_usec = (int)(group->grtt * 1000000); if (txseq < group->max_txseq) { glog5(group, "increasing seq_wrap, txseq=%u, maxseq=%u", txseq, group->max_txseq); group->seq_wrap++; } // First set nominal arrival times of missed packets for (i = group->max_txseq + 1; i != txseq; i++) { tdiff = (int)diff_usec(group->loss_history[txseq].t, group->loss_history[group->max_txseq].t) * ((i - group->max_txseq) / (txseq - group->max_txseq)); tvdiff.tv_sec = 0; tvdiff.tv_usec = tdiff; while (tvdiff.tv_usec >= 1000000) { tvdiff.tv_usec -= 1000000; tvdiff.tv_sec++; } group->loss_history[i].found = 0; group->loss_history[i].t = add_timeval(group->loss_history[group->max_txseq].t,tvdiff); } // Then check for missed packets up to MAXMISORDER less than the current // Don't do this part unless we have at least MAXMISORDER packets // TODO: address issue of start_txseq being within MAXMISORDER sequence // numbers from the maximum if (group->seq_wrap ||((uint16_t)(group->max_txseq - group->start_txseq) >= MAXMISORDER)) { for (i = group->max_txseq - MAXMISORDER; i != (uint16_t)(txseq - MAXMISORDER); i++) { if (!group->loss_history[i].found && ((diff_usec(group->loss_history[i].t, group->loss_events[0].t) > grtt_usec) || group->slowstart)) { new_loss_event(group, i); } } } group->max_txseq = txseq; if (ecn) { glog4(group, "Seq %d marked by ECN", txseq); if ((diff_usec(group->loss_history[txseq].t, group->loss_events[0].t) > grtt_usec) || group->slowstart) { new_loss_event(group, txseq); } } } group->loss_events[0].len = ((group->seq_wrap << 16) | group->max_txseq) - group->loss_events[0].start_seq; glog5(group, "current cc len = %d", group->loss_events[0].len); glog5(group, "seq_wrap=%d, max_txseq=%u, start_seq=%u", group->seq_wrap, group->max_txseq, group->loss_events[0].start_seq); }