2 NNCP -- Node to Node copy, utilities for store-and-forward data exchange
3 Copyright (C) 2016-2022 Sergey Matveev <stargrave@stargrave.org>
5 This program is free software: you can redistribute it and/or modify
6 it under the terms of the GNU General Public License as published by
7 the Free Software Foundation, version 3 of the License.
9 This program is distributed in the hope that it will be useful,
10 but WITHOUT ANY WARRANTY; without even the implied warranty of
11 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
12 GNU General Public License for more details.
14 You should have received a copy of the GNU General Public License
15 along with this program. If not, see <http://www.gnu.org/licenses/>.
34 xdr "github.com/davecgh/go-xdr/xdr2"
35 "github.com/dustin/go-humanize"
36 "github.com/flynn/noise"
40 MaxSPSize = 1<<16 - 256
43 CfgDeadline = "NNCPDEADLINE"
46 type MTHAndOffset struct {
51 type SPCheckerTask struct {
62 SPHaltMarshalized []byte
63 SPPingMarshalized []byte
65 NoiseCipherSuite noise.CipherSuite = noise.NewCipherSuite(
67 noise.CipherChaChaPoly,
71 DefaultDeadline = 10 * time.Second
72 PingTimeout = time.Minute
74 spCheckerTasks chan SPCheckerTask
75 SPCheckerWg sync.WaitGroup
76 spCheckerOnce sync.Once
79 type FdAndFullSize struct {
87 SPTypeInfo SPType = iota
88 SPTypeFreq SPType = iota
89 SPTypeFile SPType = iota
90 SPTypeDone SPType = iota
91 SPTypeHalt SPType = iota
92 SPTypePing SPType = iota
125 type FreqWithNice struct {
130 type ConnDeadlined interface {
132 SetReadDeadline(t time.Time) error
133 SetWriteDeadline(t time.Time) error
137 if v := os.Getenv(CfgDeadline); v != "" {
138 i, err := strconv.Atoi(v)
140 log.Fatalln("Can not convert", CfgDeadline, "to integer:", err)
142 DefaultDeadline = time.Duration(i) * time.Second
146 spHead := SPHead{Type: SPTypeHalt}
147 if _, err := xdr.Marshal(&buf, spHead); err != nil {
150 SPHaltMarshalized = make([]byte, SPHeadOverhead)
151 copy(SPHaltMarshalized, buf.Bytes())
154 spHead = SPHead{Type: SPTypePing}
155 if _, err := xdr.Marshal(&buf, spHead); err != nil {
158 SPPingMarshalized = make([]byte, SPHeadOverhead)
159 copy(SPPingMarshalized, buf.Bytes())
162 spInfo := SPInfo{Nice: 123, Size: 123, Hash: new([MTHSize]byte)}
163 if _, err := xdr.Marshal(&buf, spInfo); err != nil {
166 SPInfoOverhead = buf.Len()
169 spFreq := SPFreq{Hash: new([MTHSize]byte), Offset: 123}
170 if _, err := xdr.Marshal(&buf, spFreq); err != nil {
173 SPFreqOverhead = buf.Len()
176 spFile := SPFile{Hash: new([MTHSize]byte), Offset: 123}
177 if _, err := xdr.Marshal(&buf, spFile); err != nil {
180 SPFileOverhead = buf.Len()
181 spCheckerTasks = make(chan SPCheckerTask)
184 func MarshalSP(typ SPType, sp interface{}) []byte {
186 if _, err := xdr.Marshal(&buf, SPHead{typ}); err != nil {
189 if _, err := xdr.Marshal(&buf, sp); err != nil {
195 func payloadsSplit(payloads [][]byte) [][]byte {
196 var outbounds [][]byte
197 outbound := make([]byte, 0, MaxSPSize)
198 for i, payload := range payloads {
199 outbound = append(outbound, payload...)
200 if i+1 < len(payloads) && len(outbound)+len(payloads[i+1]) > MaxSPSize {
201 outbounds = append(outbounds, outbound)
202 outbound = make([]byte, 0, MaxSPSize)
205 if len(outbound) > 0 {
206 outbounds = append(outbounds, outbound)
211 type SPState struct {
216 onlineDeadline time.Duration
217 maxOnlineTime time.Duration
218 hs *noise.HandshakeState
219 csOur *noise.CipherState
220 csTheir *noise.CipherState
223 infosTheir map[[MTHSize]byte]*SPInfo
224 infosOurSeen map[[MTHSize]byte]uint8
225 queueTheir []*FreqWithNice
229 RxLastNonPing time.Time
232 TxLastNonPing time.Time
234 mustFinishAt time.Time
235 Duration time.Duration
245 onlyPkts map[[MTHSize]byte]bool
246 writeSPBuf bytes.Buffer
247 fds map[string]FdAndFullSize
249 fileHashers map[string]*MTHAndOffset
250 progressBars map[string]struct{}
254 func (state *SPState) SetDead() {
259 // Already closed channel, dead
265 for range state.payloads {
269 for range state.pings {
274 func (state *SPState) NotAlive() bool {
283 func (state *SPState) dirUnlock() {
284 state.Ctx.UnlockDir(state.rxLock)
285 state.Ctx.UnlockDir(state.txLock)
288 func (state *SPState) WriteSP(dst io.Writer, payload []byte, ping bool) error {
289 state.writeSPBuf.Reset()
290 n, err := xdr.Marshal(&state.writeSPBuf, SPRaw{
291 Magic: MagicNNCPSv1.B,
297 if n, err = dst.Write(state.writeSPBuf.Bytes()); err == nil {
298 state.TxLastSeen = time.Now()
299 state.TxBytes += int64(n)
301 state.TxLastNonPing = state.TxLastSeen
307 func (state *SPState) ReadSP(src io.Reader) ([]byte, error) {
309 n, err := xdr.UnmarshalLimited(src, &sp, 1<<17)
311 ue := err.(*xdr.UnmarshalError)
312 if ue.Err == io.EOF {
317 state.RxLastSeen = time.Now()
318 state.RxBytes += int64(n)
319 if sp.Magic != MagicNNCPSv1.B {
322 return sp.Payload, nil
325 func (ctx *Ctx) infosOur(nodeId *NodeId, nice uint8, seen *map[[MTHSize]byte]uint8) [][]byte {
328 for job := range ctx.Jobs(nodeId, TTx) {
329 if job.PktEnc.Nice > nice {
332 if _, known := (*seen)[*job.HshValue]; known {
335 totalSize += job.Size
336 infos = append(infos, &SPInfo{
337 Nice: job.PktEnc.Nice,
338 Size: uint64(job.Size),
341 (*seen)[*job.HshValue] = job.PktEnc.Nice
343 sort.Sort(ByNice(infos))
344 var payloads [][]byte
345 for _, info := range infos {
346 payloads = append(payloads, MarshalSP(SPTypeInfo, info))
347 pktName := Base32Codec.EncodeToString(info.Hash[:])
348 ctx.LogD("sp-info-our", LEs{
352 }, func(les LEs) string {
354 "Our info: %s/tx/%s (%s)",
355 ctx.NodeName(nodeId),
357 humanize.IBytes(info.Size),
362 ctx.LogI("sp-infos-tx", LEs{
365 {"Pkts", len(payloads)},
367 }, func(les LEs) string {
369 "We have got for %s: %d packets, %s",
370 ctx.NodeName(nodeId),
372 humanize.IBytes(uint64(totalSize)),
376 return payloadsSplit(payloads)
379 func (state *SPState) StartI(conn ConnDeadlined) error {
380 nodeId := state.Node.Id
381 err := state.Ctx.ensureRxDir(nodeId)
386 if !state.listOnly && (state.xxOnly == "" || state.xxOnly == TRx) {
387 rxLock, err = state.Ctx.LockDir(nodeId, string(TRx))
393 if !state.listOnly && (state.xxOnly == "" || state.xxOnly == TTx) {
394 txLock, err = state.Ctx.LockDir(nodeId, string(TTx))
399 started := time.Now()
400 conf := noise.Config{
401 CipherSuite: NoiseCipherSuite,
402 Pattern: noise.HandshakeIK,
404 StaticKeypair: noise.DHKey{
405 Private: state.Ctx.Self.NoisePrv[:],
406 Public: state.Ctx.Self.NoisePub[:],
408 PeerStatic: state.Node.NoisePub[:],
410 hs, err := noise.NewHandshakeState(conf)
415 state.payloads = make(chan []byte)
416 state.pings = make(chan struct{})
417 state.infosTheir = make(map[[MTHSize]byte]*SPInfo)
418 state.infosOurSeen = make(map[[MTHSize]byte]uint8)
419 state.progressBars = make(map[string]struct{})
420 state.started = started
421 state.rxLock = rxLock
422 state.txLock = txLock
424 var infosPayloads [][]byte
425 if !state.listOnly && (state.xxOnly == "" || state.xxOnly == TTx) {
426 infosPayloads = state.Ctx.infosOur(nodeId, state.Nice, &state.infosOurSeen)
428 var firstPayload []byte
429 if len(infosPayloads) > 0 {
430 firstPayload = infosPayloads[0]
432 // Pad first payload, to hide actual number of existing files
433 for i := 0; i < (MaxSPSize-len(firstPayload))/SPHeadOverhead; i++ {
434 firstPayload = append(firstPayload, SPHaltMarshalized...)
439 buf, _, _, err = state.hs.WriteMessage(nil, firstPayload)
444 les := LEs{{"Node", nodeId}, {"Nice", int(state.Nice)}}
445 state.Ctx.LogD("sp-startI", les, func(les LEs) string {
447 "SP with %s (nice %s): sending first message",
449 NicenessFmt(state.Nice),
452 conn.SetWriteDeadline(time.Now().Add(DefaultDeadline))
453 if err = state.WriteSP(conn, buf, false); err != nil {
454 state.Ctx.LogE("sp-startI", les, err, func(les LEs) string {
456 "SP with %s (nice %s): writing",
458 NicenessFmt(state.Nice),
464 state.Ctx.LogD("sp-startI-wait", les, func(les LEs) string {
466 "SP with %s (nice %s): waiting for first message",
468 NicenessFmt(state.Nice),
471 conn.SetReadDeadline(time.Now().Add(DefaultDeadline))
472 if buf, err = state.ReadSP(conn); err != nil {
473 state.Ctx.LogE("sp-startI-read", les, err, func(les LEs) string {
475 "SP with %s (nice %s): reading",
477 NicenessFmt(state.Nice),
483 payload, state.csOur, state.csTheir, err = state.hs.ReadMessage(nil, buf)
485 state.Ctx.LogE("sp-startI-read", les, err, func(les LEs) string {
487 "SP with %s (nice %s): reading Noise message",
489 NicenessFmt(state.Nice),
495 state.Ctx.LogD("sp-startI-workers", les, func(les LEs) string {
497 "SP with %s (nice %s): starting workers",
499 NicenessFmt(state.Nice),
502 err = state.StartWorkers(conn, infosPayloads, payload)
504 state.Ctx.LogE("sp-startI-workers", les, err, func(les LEs) string {
506 "SP with %s (nice %s): starting workers",
508 NicenessFmt(state.Nice),
516 func (state *SPState) StartR(conn ConnDeadlined) error {
517 started := time.Now()
518 conf := noise.Config{
519 CipherSuite: NoiseCipherSuite,
520 Pattern: noise.HandshakeIK,
522 StaticKeypair: noise.DHKey{
523 Private: state.Ctx.Self.NoisePrv[:],
524 Public: state.Ctx.Self.NoisePub[:],
527 hs, err := noise.NewHandshakeState(conf)
533 state.payloads = make(chan []byte)
534 state.pings = make(chan struct{})
535 state.infosOurSeen = make(map[[MTHSize]byte]uint8)
536 state.infosTheir = make(map[[MTHSize]byte]*SPInfo)
537 state.progressBars = make(map[string]struct{})
538 state.started = started
539 state.xxOnly = xxOnly
543 logMsg := func(les LEs) string {
545 "SP nice %s: waiting for first message",
546 NicenessFmt(state.Nice),
549 les := LEs{{"Nice", int(state.Nice)}}
550 state.Ctx.LogD("sp-startR", les, logMsg)
551 conn.SetReadDeadline(time.Now().Add(DefaultDeadline))
552 if buf, err = state.ReadSP(conn); err != nil {
553 state.Ctx.LogE("sp-startR-read", les, err, logMsg)
556 if payload, _, _, err = state.hs.ReadMessage(nil, buf); err != nil {
557 state.Ctx.LogE("sp-startR-read", les, err, logMsg)
562 for _, n := range state.Ctx.Neigh {
563 if n.NoisePub == nil {
566 if subtle.ConstantTimeCompare(state.hs.PeerStatic(), n.NoisePub[:]) == 1 {
572 peerId := Base32Codec.EncodeToString(state.hs.PeerStatic())
573 err = errors.New("unknown peer: " + peerId)
574 state.Ctx.LogE("sp-startR-unknown", append(les, LE{"Peer", peerId}), err, logMsg)
578 state.rxRate = node.RxRate
579 state.txRate = node.TxRate
580 state.onlineDeadline = node.OnlineDeadline
581 state.maxOnlineTime = node.MaxOnlineTime
582 les = LEs{{"Node", node.Id}, {"Nice", int(state.Nice)}}
584 if err = state.Ctx.ensureRxDir(node.Id); err != nil {
588 if xxOnly == "" || xxOnly == TRx {
589 rxLock, err = state.Ctx.LockDir(node.Id, string(TRx))
594 state.rxLock = rxLock
596 if xxOnly == "" || xxOnly == TTx {
597 txLock, err = state.Ctx.LockDir(node.Id, string(TTx))
602 state.txLock = txLock
604 var infosPayloads [][]byte
605 if xxOnly == "" || xxOnly == TTx {
606 infosPayloads = state.Ctx.infosOur(node.Id, state.Nice, &state.infosOurSeen)
608 var firstPayload []byte
609 if len(infosPayloads) > 0 {
610 firstPayload = infosPayloads[0]
612 // Pad first payload, to hide actual number of existing files
613 for i := 0; i < (MaxSPSize-len(firstPayload))/SPHeadOverhead; i++ {
614 firstPayload = append(firstPayload, SPHaltMarshalized...)
617 state.Ctx.LogD("sp-startR-write", les, func(les LEs) string {
619 "SP with %s (nice %s): sending first message",
620 node.Name, NicenessFmt(state.Nice),
623 buf, state.csTheir, state.csOur, err = state.hs.WriteMessage(nil, firstPayload)
628 conn.SetWriteDeadline(time.Now().Add(DefaultDeadline))
629 if err = state.WriteSP(conn, buf, false); err != nil {
630 state.Ctx.LogE("sp-startR-write", les, err, func(les LEs) string {
632 "SP with %s (nice %s): writing",
633 node.Name, NicenessFmt(state.Nice),
639 state.Ctx.LogD("sp-startR-workers", les, func(les LEs) string {
641 "SP with %s (nice %s): starting workers",
642 node.Name, NicenessFmt(state.Nice),
645 err = state.StartWorkers(conn, infosPayloads, payload)
652 func (state *SPState) closeFd(pth string) {
654 if s, exists := state.fds[pth]; exists {
655 delete(state.fds, pth)
658 state.fdsLock.Unlock()
661 func (state *SPState) StartWorkers(
663 infosPayloads [][]byte,
666 les := LEs{{"Node", state.Node.Id}, {"Nice", int(state.Nice)}}
667 state.fds = make(map[string]FdAndFullSize)
668 state.fileHashers = make(map[string]*MTHAndOffset)
669 state.isDead = make(chan struct{})
670 if state.maxOnlineTime > 0 {
671 state.mustFinishAt = state.started.Add(state.maxOnlineTime)
674 spCheckerOnce.Do(func() { go SPChecker(state.Ctx) })
676 for job := range state.Ctx.JobsNoCK(state.Node.Id) {
677 if job.PktEnc.Nice <= state.Nice {
678 spCheckerTasks <- SPCheckerTask{
679 nodeId: state.Node.Id,
681 done: state.payloads,
688 // Remaining handshake payload sending
689 if len(infosPayloads) > 1 {
692 for _, payload := range infosPayloads[1:] {
694 "sp-queue-remaining",
695 append(les, LE{"Size", int64(len(payload))}),
696 func(les LEs) string {
698 "SP with %s (nice %s): queuing remaining payload (%s)",
699 state.Node.Name, NicenessFmt(state.Nice),
700 humanize.IBytes(uint64(len(payload))),
704 state.payloads <- payload
710 // Processing of first payload and queueing its responses
711 logMsg := func(les LEs) string {
713 "SP with %s (nice %s): processing first payload (%s)",
714 state.Node.Name, NicenessFmt(state.Nice),
715 humanize.IBytes(uint64(len(payload))),
718 state.Ctx.LogD("sp-process", append(les, LE{"Size", int64(len(payload))}), logMsg)
719 replies, err := state.ProcessSP(payload)
721 state.Ctx.LogE("sp-process", les, err, logMsg)
726 for _, reply := range replies {
729 append(les, LE{"Size", int64(len(reply))}),
730 func(les LEs) string {
732 "SP with %s (nice %s): queuing reply (%s)",
733 state.Node.Name, NicenessFmt(state.Nice),
734 humanize.IBytes(uint64(len(payload))),
738 state.payloads <- reply
746 deadlineTicker := time.NewTicker(time.Second)
747 pingTicker := time.NewTicker(PingTimeout)
752 deadlineTicker.Stop()
755 case now := <-deadlineTicker.C:
756 if now.Sub(state.RxLastNonPing) >= state.onlineDeadline &&
757 now.Sub(state.TxLastNonPing) >= state.onlineDeadline {
760 if state.maxOnlineTime > 0 && state.mustFinishAt.Before(now) {
763 if now.Sub(state.RxLastSeen) >= 2*PingTimeout {
770 case now := <-pingTicker.C:
771 if now.After(state.TxLastSeen.Add(PingTimeout)) {
774 state.pings <- struct{}{}
782 // Spool checker and INFOs sender of appearing files
783 if !state.listOnly && (state.xxOnly == "" || state.xxOnly == TTx) {
786 dw, err := state.Ctx.NewDirWatcher(
787 filepath.Join(state.Ctx.Spool, state.Node.Id.String(), string(TTx)),
791 state.Ctx.LogE("sp-queue-dir-watch", les, err, logMsg)
801 for _, payload := range state.Ctx.infosOur(
808 append(les, LE{"Size", int64(len(payload))}),
809 func(les LEs) string {
811 "SP with %s (nice %s): queuing new info (%s)",
812 state.Node.Name, NicenessFmt(state.Nice),
813 humanize.IBytes(uint64(len(payload))),
817 state.payloads <- payload
828 defer state.SetDead()
829 defer state.wg.Done()
830 buf := make([]byte, MaxSPSize-SPHeadOverhead-SPFileOverhead)
832 if state.NotAlive() {
839 state.Ctx.LogD("sp-got-ping", les, func(les LEs) string {
841 "SP with %s (nice %s): got ping",
842 state.Node.Name, NicenessFmt(state.Nice),
845 payload = SPPingMarshalized
847 case payload = <-state.payloads:
850 append(les, LE{"Size", int64(len(payload))}),
851 func(les LEs) string {
853 "SP with %s (nice %s): got payload (%s)",
854 state.Node.Name, NicenessFmt(state.Nice),
855 humanize.IBytes(uint64(len(payload))),
861 if len(state.queueTheir) == 0 {
863 time.Sleep(100 * time.Millisecond)
866 freq := state.queueTheir[0].freq
868 if state.txRate > 0 {
869 time.Sleep(time.Second / time.Duration(state.txRate))
871 pktName := Base32Codec.EncodeToString(freq.Hash[:])
874 LE{"XX", string(TTx)},
876 LE{"Size", int64(freq.Offset)},
878 logMsg := func(les LEs) string {
880 "SP with %s (nice %s): tx/%s (%s)",
881 state.Node.Name, NicenessFmt(state.Nice),
883 humanize.IBytes(freq.Offset),
886 state.Ctx.LogD("sp-queue", lesp, func(les LEs) string {
887 return logMsg(les) + ": queueing"
889 pth := filepath.Join(
891 state.Node.Id.String(),
893 Base32Codec.EncodeToString(freq.Hash[:]),
895 state.fdsLock.RLock()
896 fdAndFullSize, exists := state.fds[pth]
897 state.fdsLock.RUnlock()
899 state.Ctx.LogD("sp-queue-open", lesp, func(les LEs) string {
900 return logMsg(les) + ": opening"
902 fd, err := os.Open(pth)
904 state.Ctx.LogE("sp-queue-open", lesp, err, func(les LEs) string {
905 return logMsg(les) + ": opening"
911 state.Ctx.LogE("sp-queue-stat", lesp, err, func(les LEs) string {
912 return logMsg(les) + ": stating"
916 fdAndFullSize = FdAndFullSize{fd: fd, fullSize: fi.Size()}
918 state.fds[pth] = fdAndFullSize
919 state.fdsLock.Unlock()
921 fd := fdAndFullSize.fd
922 fullSize := fdAndFullSize.fullSize
923 lesp = append(lesp, LE{"FullSize", fullSize})
925 if freq.Offset < uint64(fullSize) {
926 state.Ctx.LogD("sp-file-seek", lesp, func(les LEs) string {
927 return logMsg(les) + ": seeking"
929 if _, err = fd.Seek(int64(freq.Offset), io.SeekStart); err != nil {
930 state.Ctx.LogE("sp-file-seek", lesp, err, func(les LEs) string {
931 return logMsg(les) + ": seeking"
935 n, err := fd.Read(buf)
937 state.Ctx.LogE("sp-file-read", lesp, err, func(les LEs) string {
938 return logMsg(les) + ": reading"
945 LE{"XX", string(TTx)},
947 LE{"Size", int64(n)},
948 LE{"FullSize", fullSize},
950 state.Ctx.LogD("sp-file-read", lesp, func(les LEs) string {
953 logMsg(les), humanize.IBytes(uint64(n)),
959 payload = MarshalSP(SPTypeFile, SPFile{
964 ourSize := freq.Offset + uint64(len(bufRead))
967 LE{"XX", string(TTx)},
969 LE{"Size", int64(ourSize)},
970 LE{"FullSize", fullSize},
972 if state.Ctx.ShowPrgrs {
973 state.progressBars[pktName] = struct{}{}
976 if ourSize == uint64(fullSize) {
978 state.Ctx.LogD("sp-file-finished", lesp, func(les LEs) string {
979 return logMsg(les) + ": finished"
981 if state.Ctx.ShowPrgrs {
982 delete(state.progressBars, pktName)
986 for i, q := range state.queueTheir {
987 if *q.freq.Hash != *freq.Hash {
990 if ourSize == uint64(fullSize) {
991 state.queueTheir = append(
992 state.queueTheir[:i],
993 state.queueTheir[i+1:]...,
996 q.freq.Offset = ourSize
1002 logMsg := func(les LEs) string {
1004 "SP with %s (nice %s): sending %s",
1005 state.Node.Name, NicenessFmt(state.Nice),
1006 humanize.IBytes(uint64(len(payload))),
1009 state.Ctx.LogD("sp-sending", append(les, LE{"Size", int64(len(payload))}), logMsg)
1010 conn.SetWriteDeadline(time.Now().Add(DefaultDeadline))
1011 ct, err := state.csOur.Encrypt(nil, nil, payload)
1013 state.Ctx.LogE("sp-encrypting", les, err, logMsg)
1016 if err := state.WriteSP(conn, ct, ping); err != nil {
1017 state.Ctx.LogE("sp-sending", les, err, logMsg)
1027 if state.NotAlive() {
1030 logMsg := func(les LEs) string {
1032 "SP with %s (nice %s): waiting for payload",
1033 state.Node.Name, NicenessFmt(state.Nice),
1036 state.Ctx.LogD("sp-recv-wait", les, logMsg)
1037 conn.SetReadDeadline(time.Now().Add(DefaultDeadline))
1038 payload, err := state.ReadSP(conn)
1043 unmarshalErr := err.(*xdr.UnmarshalError)
1044 if os.IsTimeout(unmarshalErr.Err) {
1047 if unmarshalErr.ErrorCode == xdr.ErrIO {
1050 state.Ctx.LogE("sp-recv-wait", les, err, logMsg)
1053 logMsg = func(les LEs) string {
1055 "SP with %s (nice %s): payload (%s)",
1056 state.Node.Name, NicenessFmt(state.Nice),
1057 humanize.IBytes(uint64(len(payload))),
1062 append(les, LE{"Size", int64(len(payload))}),
1063 func(les LEs) string { return logMsg(les) + ": got" },
1065 payload, err = state.csTheir.Decrypt(nil, nil, payload)
1067 state.Ctx.LogE("sp-recv-got", les, err, func(les LEs) string {
1068 return logMsg(les) + ": got"
1074 append(les, LE{"Size", int64(len(payload))}),
1075 func(les LEs) string {
1076 return logMsg(les) + ": processing"
1079 replies, err := state.ProcessSP(payload)
1081 state.Ctx.LogE("sp-recv-process", les, err, func(les LEs) string {
1082 return logMsg(les) + ": processing"
1088 for _, reply := range replies {
1091 append(les[:len(les)-1], LE{"Size", int64(len(reply))}),
1092 func(les LEs) string {
1094 "SP with %s (nice %s): queuing reply (%s)",
1095 state.Node.Name, NicenessFmt(state.Nice),
1096 humanize.IBytes(uint64(len(reply))),
1100 state.payloads <- reply
1104 if state.rxRate > 0 {
1105 time.Sleep(time.Second / time.Duration(state.rxRate))
1117 func (state *SPState) Wait() bool {
1119 close(state.payloads)
1121 state.Duration = time.Now().Sub(state.started)
1123 state.RxSpeed = state.RxBytes
1124 state.TxSpeed = state.TxBytes
1125 rxDuration := int64(state.RxLastSeen.Sub(state.started).Seconds())
1126 txDuration := int64(state.TxLastSeen.Sub(state.started).Seconds())
1128 state.RxSpeed = state.RxBytes / rxDuration
1131 state.TxSpeed = state.TxBytes / txDuration
1133 nothingLeft := len(state.queueTheir) == 0
1134 for _, s := range state.fds {
1138 for pktName := range state.progressBars {
1139 ProgressKill(pktName)
1144 func (state *SPState) ProcessSP(payload []byte) ([][]byte, error) {
1145 les := LEs{{"Node", state.Node.Id}, {"Nice", int(state.Nice)}}
1146 r := bytes.NewReader(payload)
1148 var replies [][]byte
1151 state.Ctx.LogD("sp-process-unmarshal", les, func(les LEs) string {
1153 "SP with %s (nice %s): unmarshaling header",
1154 state.Node.Name, NicenessFmt(state.Nice),
1158 if _, err = xdr.Unmarshal(r, &head); err != nil {
1159 state.Ctx.LogE("sp-process-unmarshal", les, err, func(les LEs) string {
1161 "SP with %s (nice %s): unmarshaling header",
1162 state.Node.Name, NicenessFmt(state.Nice),
1167 if head.Type != SPTypePing {
1168 state.RxLastNonPing = state.RxLastSeen
1174 append(les, LE{"Type", "halt"}), func(les LEs) string {
1176 "SP with %s (nice %s): got HALT",
1177 state.Node.Name, NicenessFmt(state.Nice),
1182 state.queueTheir = nil
1188 append(les, LE{"Type", "ping"}),
1189 func(les LEs) string {
1191 "SP with %s (nice %s): got PING",
1192 state.Node.Name, NicenessFmt(state.Nice),
1199 lesp := append(les, LE{"Type", "info"})
1201 "sp-process-info-unmarshal", lesp,
1202 func(les LEs) string {
1204 "SP with %s (nice %s): unmarshaling INFO",
1205 state.Node.Name, NicenessFmt(state.Nice),
1210 if _, err = xdr.Unmarshal(r, &info); err != nil {
1212 "sp-process-info-unmarshal", lesp, err,
1213 func(les LEs) string {
1215 "SP with %s (nice %s): unmarshaling INFO",
1216 state.Node.Name, NicenessFmt(state.Nice),
1222 pktName := Base32Codec.EncodeToString(info.Hash[:])
1226 LE{"Size", int64(info.Size)},
1227 LE{"PktNice", int(info.Nice)},
1229 logMsg := func(les LEs) string {
1231 "SP with %s (nice %s): INFO %s (%s) nice %s",
1232 state.Node.Name, NicenessFmt(state.Nice),
1234 humanize.IBytes(info.Size),
1235 NicenessFmt(info.Nice),
1238 if !state.listOnly && info.Nice > state.Nice {
1239 state.Ctx.LogD("sp-process-info-too-nice", lesp, func(les LEs) string {
1240 return logMsg(les) + ": too nice"
1244 state.Ctx.LogD("sp-process-info-got", lesp, func(les LEs) string {
1245 return logMsg(les) + ": received"
1247 if !state.listOnly && state.xxOnly == TTx {
1251 state.infosTheir[*info.Hash] = &info
1253 state.Ctx.LogD("sp-process-info-stat", lesp, func(les LEs) string {
1254 return logMsg(les) + ": stating part"
1256 pktPath := filepath.Join(
1258 state.Node.Id.String(),
1260 Base32Codec.EncodeToString(info.Hash[:]),
1262 logMsg = func(les LEs) string {
1264 "Packet %s (%s) (nice %s)",
1266 humanize.IBytes(info.Size),
1267 NicenessFmt(info.Nice),
1270 if _, err = os.Stat(pktPath); err == nil {
1271 state.Ctx.LogI("sp-info-done", lesp, func(les LEs) string {
1272 return logMsg(les) + ": already done"
1274 if !state.listOnly {
1275 replies = append(replies, MarshalSP(SPTypeDone, SPDone{info.Hash}))
1279 if _, err = os.Stat(filepath.Join(
1280 state.Ctx.Spool, state.Node.Id.String(), string(TRx),
1281 SeenDir, Base32Codec.EncodeToString(info.Hash[:]),
1283 state.Ctx.LogI("sp-info-seen", lesp, func(les LEs) string {
1284 return logMsg(les) + ": already seen"
1286 if !state.listOnly {
1287 replies = append(replies, MarshalSP(SPTypeDone, SPDone{info.Hash}))
1291 if _, err = os.Stat(pktPath + NoCKSuffix); err == nil {
1292 state.Ctx.LogI("sp-info-nock", lesp, func(les LEs) string {
1293 return logMsg(les) + ": still not checksummed"
1297 fi, err := os.Stat(pktPath + PartSuffix)
1302 if !state.Ctx.IsEnoughSpace(int64(info.Size) - offset) {
1303 state.Ctx.LogI("sp-info-no-space", lesp, func(les LEs) string {
1304 return logMsg(les) + ": not enough space"
1310 append(lesp, LE{"Offset", offset}),
1311 func(les LEs) string {
1313 "%s: %d%%", logMsg(les), 100*uint64(offset)/info.Size,
1317 if !state.listOnly && (state.onlyPkts == nil || state.onlyPkts[*info.Hash]) {
1318 replies = append(replies, MarshalSP(
1320 SPFreq{info.Hash, uint64(offset)},
1325 lesp := append(les, LE{"Type", "file"})
1326 state.Ctx.LogD("sp-process-file", lesp, func(les LEs) string {
1328 "SP with %s (nice %s): unmarshaling FILE",
1329 state.Node.Name, NicenessFmt(state.Nice),
1333 if _, err = xdr.Unmarshal(r, &file); err != nil {
1334 state.Ctx.LogE("sp-process-file", lesp, err, func(les LEs) string {
1336 "SP with %s (nice %s): unmarshaling FILE",
1337 state.Node.Name, NicenessFmt(state.Nice),
1342 pktName := Base32Codec.EncodeToString(file.Hash[:])
1345 LE{"XX", string(TRx)},
1347 LE{"Size", int64(len(file.Payload))},
1349 logMsg := func(les LEs) string {
1351 "Got packet %s (%s)",
1352 pktName, humanize.IBytes(uint64(len(file.Payload))),
1355 fullsize := int64(0)
1357 infoTheir := state.infosTheir[*file.Hash]
1359 if infoTheir == nil {
1360 state.Ctx.LogE("sp-file-open", lesp, err, func(les LEs) string {
1361 return logMsg(les) + ": unknown file"
1365 fullsize = int64(infoTheir.Size)
1366 lesp = append(lesp, LE{"FullSize", fullsize})
1367 dirToSync := filepath.Join(
1369 state.Node.Id.String(),
1372 filePath := filepath.Join(dirToSync, pktName)
1373 filePathPart := filePath + PartSuffix
1374 state.Ctx.LogD("sp-file-open", lesp, func(les LEs) string {
1375 return logMsg(les) + ": opening part"
1377 state.fdsLock.RLock()
1378 fdAndFullSize, exists := state.fds[filePathPart]
1379 state.fdsLock.RUnlock()
1380 hasherAndOffset := state.fileHashers[filePath]
1383 fd = fdAndFullSize.fd
1385 fd, err = os.OpenFile(
1387 os.O_RDWR|os.O_CREATE,
1391 state.Ctx.LogE("sp-file-open", lesp, err, func(les LEs) string {
1392 return logMsg(les) + ": opening part"
1396 state.fdsLock.Lock()
1397 state.fds[filePathPart] = FdAndFullSize{fd: fd}
1398 state.fdsLock.Unlock()
1400 hasherAndOffset = &MTHAndOffset{
1401 mth: MTHNew(fullsize, int64(file.Offset)),
1402 offset: file.Offset,
1404 state.fileHashers[filePath] = hasherAndOffset
1409 append(lesp, LE{"Offset", file.Offset}),
1410 func(les LEs) string {
1411 return fmt.Sprintf("%s: seeking %d", logMsg(les), file.Offset)
1413 if _, err = fd.Seek(int64(file.Offset), io.SeekStart); err != nil {
1414 state.Ctx.LogE("sp-file-seek", lesp, err, func(les LEs) string {
1415 return logMsg(les) + ": seeking"
1417 state.closeFd(filePathPart)
1420 state.Ctx.LogD("sp-file-write", lesp, func(les LEs) string {
1421 return logMsg(les) + ": writing"
1423 if _, err = fd.Write(file.Payload); err != nil {
1424 state.Ctx.LogE("sp-file-write", lesp, err, func(les LEs) string {
1425 return logMsg(les) + ": writing"
1427 state.closeFd(filePathPart)
1430 if hasherAndOffset != nil {
1431 if hasherAndOffset.offset == file.Offset {
1432 if _, err = hasherAndOffset.mth.Write(file.Payload); err != nil {
1435 hasherAndOffset.offset += uint64(len(file.Payload))
1438 "sp-file-offset-differs", lesp, errors.New("offset differs"),
1439 func(les LEs) string {
1440 return logMsg(les) + ": deleting hasher"
1443 delete(state.fileHashers, filePath)
1444 hasherAndOffset = nil
1447 ourSize := int64(file.Offset + uint64(len(file.Payload)))
1448 lesp[len(lesp)-2].V = ourSize
1449 if state.Ctx.ShowPrgrs {
1450 state.progressBars[pktName] = struct{}{}
1451 Progress("Rx", lesp)
1453 if fullsize != ourSize {
1456 if state.Ctx.ShowPrgrs {
1457 delete(state.progressBars, pktName)
1459 logMsg = func(les LEs) string {
1461 "Got packet %s %d%% (%s / %s)",
1462 pktName, 100*ourSize/fullsize,
1463 humanize.IBytes(uint64(ourSize)),
1464 humanize.IBytes(uint64(fullsize)),
1470 state.Ctx.LogE("sp-file-sync", lesp, err, func(les LEs) string {
1471 return logMsg(les) + ": syncing"
1473 state.closeFd(filePathPart)
1477 if hasherAndOffset != nil {
1478 delete(state.fileHashers, filePath)
1479 if hasherAndOffset.mth.PreaddSize() == 0 {
1480 if bytes.Compare(hasherAndOffset.mth.Sum(nil), file.Hash[:]) != 0 {
1482 "sp-file-bad-checksum", lesp,
1483 errors.New("checksum mismatch"),
1486 state.closeFd(filePathPart)
1489 if err = os.Rename(filePathPart, filePath); err != nil {
1490 state.Ctx.LogE("sp-file-rename", lesp, err, func(les LEs) string {
1491 return logMsg(les) + ": renaming"
1493 state.closeFd(filePathPart)
1496 if err = DirSync(dirToSync); err != nil {
1497 state.Ctx.LogE("sp-file-dirsync", lesp, err, func(les LEs) string {
1498 return logMsg(les) + ": dirsyncing"
1500 state.closeFd(filePathPart)
1503 state.Ctx.LogI("sp-file-done", lesp, func(les LEs) string {
1504 return logMsg(les) + ": done"
1508 state.payloads <- MarshalSP(SPTypeDone, SPDone{file.Hash})
1512 delete(state.infosTheir, *file.Hash)
1514 if !state.Ctx.HdrUsage {
1517 if _, err = fd.Seek(0, io.SeekStart); err != nil {
1518 state.Ctx.LogE("sp-file-seek", lesp, err, func(les LEs) string {
1519 return logMsg(les) + ": seeking"
1521 state.closeFd(filePathPart)
1524 _, pktEncRaw, err := state.Ctx.HdrRead(fd)
1525 state.closeFd(filePathPart)
1527 state.Ctx.LogE("sp-file-hdr-read", lesp, err, func(les LEs) string {
1528 return logMsg(les) + ": HdrReading"
1532 state.Ctx.HdrWrite(pktEncRaw, filePath)
1536 state.closeFd(filePathPart)
1537 if err = os.Rename(filePathPart, filePath+NoCKSuffix); err != nil {
1538 state.Ctx.LogE("sp-file-rename", lesp, err, func(les LEs) string {
1539 return logMsg(les) + ": renaming"
1543 if err = DirSync(dirToSync); err != nil {
1544 state.Ctx.LogE("sp-file-dirsync", lesp, err, func(les LEs) string {
1545 return logMsg(les) + ": dirsyncing"
1549 state.Ctx.LogI("sp-file-downloaded", lesp, func(les LEs) string {
1550 return logMsg(les) + ": downloaded"
1553 delete(state.infosTheir, *file.Hash)
1557 nodeId: state.Node.Id,
1559 done: state.payloads,
1561 if hasherAndOffset != nil {
1562 t.mth = hasherAndOffset.mth
1568 lesp := append(les, LE{"Type", "done"})
1569 state.Ctx.LogD("sp-process-done-unmarshal", lesp, func(les LEs) string {
1571 "SP with %s (nice %s): unmarshaling DONE",
1572 state.Node.Name, NicenessFmt(state.Nice),
1576 if _, err = xdr.Unmarshal(r, &done); err != nil {
1577 state.Ctx.LogE("sp-process-done-unmarshal", lesp, err, func(les LEs) string {
1579 "SP with %s (nice %s): unmarshaling DONE",
1580 state.Node.Name, NicenessFmt(state.Nice),
1585 pktName := Base32Codec.EncodeToString(done.Hash[:])
1586 lesp = append(lesp, LE{"Pkt", pktName}, LE{"XX", string(TTx)})
1587 logMsg := func(les LEs) string {
1589 "SP with %s (nice %s): DONE: removing %s",
1590 state.Node.Name, NicenessFmt(state.Nice), pktName,
1593 state.Ctx.LogD("sp-done", lesp, logMsg)
1594 pth := filepath.Join(
1596 state.Node.Id.String(),
1600 if err = os.Remove(pth); err == nil {
1601 state.Ctx.LogI("sp-done", lesp, func(les LEs) string {
1602 return fmt.Sprintf("Packet %s is sent", pktName)
1604 if state.Ctx.HdrUsage {
1605 os.Remove(JobPath2Hdr(pth))
1608 state.Ctx.LogE("sp-done", lesp, err, logMsg)
1612 lesp := append(les, LE{"Type", "freq"})
1613 state.Ctx.LogD("sp-process-freq", lesp, func(les LEs) string {
1615 "SP with %s (nice %s): unmarshaling FREQ",
1616 state.Node.Name, NicenessFmt(state.Nice),
1620 if _, err = xdr.Unmarshal(r, &freq); err != nil {
1621 state.Ctx.LogE("sp-process-freq", lesp, err, func(les LEs) string {
1623 "SP with %s (nice %s): unmarshaling FREQ",
1624 state.Node.Name, NicenessFmt(state.Nice),
1629 pktName := Base32Codec.EncodeToString(freq.Hash[:])
1630 lesp = append(lesp, LE{"Pkt", pktName}, LE{"Offset", freq.Offset})
1631 state.Ctx.LogD("sp-process-freq-queueing", lesp, func(les LEs) string {
1633 "SP with %s (nice %s): FREQ %s: queuing",
1634 state.Node.Name, NicenessFmt(state.Nice), pktName,
1637 nice, exists := state.infosOurSeen[*freq.Hash]
1639 if state.onlyPkts == nil || !state.onlyPkts[*freq.Hash] {
1642 var freqWithNice *FreqWithNice
1643 for insertIdx, freqWithNice = range state.queueTheir {
1644 if freqWithNice.nice > nice {
1648 state.queueTheir = append(state.queueTheir, nil)
1649 copy(state.queueTheir[insertIdx+1:], state.queueTheir[insertIdx:])
1650 state.queueTheir[insertIdx] = &FreqWithNice{&freq, nice}
1653 state.Ctx.LogD("sp-process-freq-skip", lesp, func(les LEs) string {
1655 "SP with %s (nice %s): FREQ %s: skipping",
1656 state.Node.Name, NicenessFmt(state.Nice), pktName,
1661 state.Ctx.LogD("sp-process-freq-unknown", lesp, func(les LEs) string {
1663 "SP with %s (nice %s): FREQ %s: unknown",
1664 state.Node.Name, NicenessFmt(state.Nice), pktName,
1671 "sp-process-type-unknown",
1672 append(les, LE{"Type", head.Type}),
1673 errors.New("unknown type"),
1674 func(les LEs) string {
1676 "SP with %s (nice %s): %d",
1677 state.Node.Name, NicenessFmt(state.Nice), head.Type,
1681 return nil, BadPktType
1689 for _, info := range state.infosTheir {
1694 state.Ctx.LogI("sp-infos-rx", LEs{
1695 {"XX", string(TRx)},
1696 {"Node", state.Node.Id},
1698 {"Size", int64(size)},
1699 }, func(les LEs) string {
1701 "%s has got for us: %d packets, %s",
1702 state.Node.Name, pkts, humanize.IBytes(size),
1706 return payloadsSplit(replies), nil
1709 func SPChecker(ctx *Ctx) {
1710 for t := range spCheckerTasks {
1711 pktName := Base32Codec.EncodeToString(t.hsh[:])
1713 {"XX", string(TRx)},
1718 ctx.LogD("sp-checker", les, func(les LEs) string {
1719 return fmt.Sprintf("Checksumming %s/rx/%s", ctx.NodeName(t.nodeId), pktName)
1721 size, err := ctx.CheckNoCK(t.nodeId, t.hsh, t.mth)
1722 les = append(les, LE{"Size", size})
1724 ctx.LogE("sp-checker", les, err, func(les LEs) string {
1726 "Checksumming %s/rx/%s (%s)", ctx.NodeName(t.nodeId), pktName,
1727 humanize.IBytes(uint64(size)),
1733 ctx.LogI("sp-checker-done", les, func(les LEs) string {
1735 "Packet %s is retreived (%s)",
1736 pktName, humanize.IBytes(uint64(size)),
1740 go func(t SPCheckerTask) {
1741 defer func() { recover() }()
1742 t.done <- MarshalSP(SPTypeDone, SPDone{t.hsh})