2 NNCP -- Node to Node copy, utilities for store-and-forward data exchange
3 Copyright (C) 2016-2021 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/>.
33 xdr "github.com/davecgh/go-xdr/xdr2"
34 "github.com/dustin/go-humanize"
35 "github.com/flynn/noise"
36 "golang.org/x/crypto/blake2b"
40 MaxSPSize = 1<<16 - 256
45 type SPCheckerQueues struct {
46 appeared chan *[32]byte
47 checked chan *[32]byte
51 MagicNNCPLv1 [8]byte = [8]byte{'N', 'N', 'C', 'P', 'S', 0, 0, 1}
56 SPHaltMarshalized []byte
57 SPPingMarshalized []byte
59 NoiseCipherSuite noise.CipherSuite = noise.NewCipherSuite(
61 noise.CipherChaChaPoly,
65 DefaultDeadline = 10 * time.Second
66 PingTimeout = time.Minute
68 spCheckers = make(map[NodeId]*SPCheckerQueues)
71 type FdAndFullSize struct {
76 type HasherAndOffset struct {
84 SPTypeInfo SPType = iota
85 SPTypeFreq SPType = iota
86 SPTypeFile SPType = iota
87 SPTypeDone SPType = iota
88 SPTypeHalt SPType = iota
89 SPTypePing SPType = iota
122 type FreqWithNice struct {
127 type ConnDeadlined interface {
129 SetReadDeadline(t time.Time) error
130 SetWriteDeadline(t time.Time) error
135 spHead := SPHead{Type: SPTypeHalt}
136 if _, err := xdr.Marshal(&buf, spHead); err != nil {
139 SPHaltMarshalized = make([]byte, SPHeadOverhead)
140 copy(SPHaltMarshalized, buf.Bytes())
143 spHead = SPHead{Type: SPTypePing}
144 if _, err := xdr.Marshal(&buf, spHead); err != nil {
147 SPPingMarshalized = make([]byte, SPHeadOverhead)
148 copy(SPPingMarshalized, buf.Bytes())
151 spInfo := SPInfo{Nice: 123, Size: 123, Hash: new([32]byte)}
152 if _, err := xdr.Marshal(&buf, spInfo); err != nil {
155 SPInfoOverhead = buf.Len()
158 spFreq := SPFreq{Hash: new([32]byte), Offset: 123}
159 if _, err := xdr.Marshal(&buf, spFreq); err != nil {
162 SPFreqOverhead = buf.Len()
165 spFile := SPFile{Hash: new([32]byte), Offset: 123}
166 if _, err := xdr.Marshal(&buf, spFile); err != nil {
169 SPFileOverhead = buf.Len()
172 func MarshalSP(typ SPType, sp interface{}) []byte {
174 if _, err := xdr.Marshal(&buf, SPHead{typ}); err != nil {
177 if _, err := xdr.Marshal(&buf, sp); err != nil {
183 func payloadsSplit(payloads [][]byte) [][]byte {
184 var outbounds [][]byte
185 outbound := make([]byte, 0, MaxSPSize)
186 for i, payload := range payloads {
187 outbound = append(outbound, payload...)
188 if i+1 < len(payloads) && len(outbound)+len(payloads[i+1]) > MaxSPSize {
189 outbounds = append(outbounds, outbound)
190 outbound = make([]byte, 0, MaxSPSize)
193 if len(outbound) > 0 {
194 outbounds = append(outbounds, outbound)
199 type SPState struct {
204 onlineDeadline time.Duration
205 maxOnlineTime time.Duration
206 hs *noise.HandshakeState
207 csOur *noise.CipherState
208 csTheir *noise.CipherState
211 infosTheir map[[32]byte]*SPInfo
212 infosOurSeen map[[32]byte]uint8
213 queueTheir []*FreqWithNice
217 RxLastNonPing time.Time
220 TxLastNonPing time.Time
222 mustFinishAt time.Time
223 Duration time.Duration
233 onlyPkts map[[32]byte]bool
234 writeSPBuf bytes.Buffer
235 fds map[string]FdAndFullSize
237 fileHashers map[string]*HasherAndOffset
238 checkerQueues SPCheckerQueues
239 progressBars map[string]struct{}
243 func (state *SPState) SetDead() {
248 // Already closed channel, dead
254 for range state.payloads {
258 for range state.pings {
263 func (state *SPState) NotAlive() bool {
272 func (state *SPState) dirUnlock() {
273 state.Ctx.UnlockDir(state.rxLock)
274 state.Ctx.UnlockDir(state.txLock)
277 func SPChecker(ctx *Ctx, nodeId *NodeId, appeared, checked chan *[32]byte) {
278 for hshValue := range appeared {
279 pktName := Base32Codec.EncodeToString(hshValue[:])
285 ctx.LogD("sp-checker", les, func(les LEs) string {
286 return fmt.Sprintf("Checksumming %s/rx/%s", ctx.NodeName(nodeId), pktName)
288 size, err := ctx.CheckNoCK(nodeId, hshValue)
289 les = append(les, LE{"Size", size})
291 ctx.LogE("sp-checker", les, err, func(les LEs) string {
293 "Checksumming %s/rx/%s (%s)", ctx.NodeName(nodeId), pktName,
294 humanize.IBytes(uint64(size)),
299 ctx.LogI("sp-checker-done", les, func(les LEs) string {
301 "Packet %s is retreived (%s)",
302 pktName, humanize.IBytes(uint64(size)),
305 go func(hsh *[32]byte) { checked <- hsh }(hshValue)
309 func (state *SPState) WriteSP(dst io.Writer, payload []byte, ping bool) error {
310 state.writeSPBuf.Reset()
311 n, err := xdr.Marshal(&state.writeSPBuf, SPRaw{
318 if n, err = dst.Write(state.writeSPBuf.Bytes()); err == nil {
319 state.TxLastSeen = time.Now()
320 state.TxBytes += int64(n)
322 state.TxLastNonPing = state.TxLastSeen
328 func (state *SPState) ReadSP(src io.Reader) ([]byte, error) {
330 n, err := xdr.UnmarshalLimited(src, &sp, 1<<17)
332 ue := err.(*xdr.UnmarshalError)
333 if ue.Err == io.EOF {
338 state.RxLastSeen = time.Now()
339 state.RxBytes += int64(n)
340 if sp.Magic != MagicNNCPLv1 {
343 return sp.Payload, nil
346 func (ctx *Ctx) infosOur(nodeId *NodeId, nice uint8, seen *map[[32]byte]uint8) [][]byte {
349 for job := range ctx.Jobs(nodeId, TTx) {
350 if job.PktEnc.Nice > nice {
353 if _, known := (*seen)[*job.HshValue]; known {
356 totalSize += job.Size
357 infos = append(infos, &SPInfo{
358 Nice: job.PktEnc.Nice,
359 Size: uint64(job.Size),
362 (*seen)[*job.HshValue] = job.PktEnc.Nice
364 sort.Sort(ByNice(infos))
365 var payloads [][]byte
366 for _, info := range infos {
367 payloads = append(payloads, MarshalSP(SPTypeInfo, info))
368 pktName := Base32Codec.EncodeToString(info.Hash[:])
369 ctx.LogD("sp-info-our", LEs{
373 }, func(les LEs) string {
375 "Our info: %s/tx/%s (%s)",
376 ctx.NodeName(nodeId),
378 humanize.IBytes(info.Size),
383 ctx.LogI("sp-infos-tx", LEs{
386 {"Pkts", len(payloads)},
388 }, func(les LEs) string {
390 "We have got for %s: %d packets, %s",
391 ctx.NodeName(nodeId),
393 humanize.IBytes(uint64(totalSize)),
397 return payloadsSplit(payloads)
400 func (state *SPState) StartI(conn ConnDeadlined) error {
401 nodeId := state.Node.Id
402 err := state.Ctx.ensureRxDir(nodeId)
407 if !state.listOnly && (state.xxOnly == "" || state.xxOnly == TRx) {
408 rxLock, err = state.Ctx.LockDir(nodeId, string(TRx))
414 if !state.listOnly && (state.xxOnly == "" || state.xxOnly == TTx) {
415 txLock, err = state.Ctx.LockDir(nodeId, string(TTx))
420 started := time.Now()
421 conf := noise.Config{
422 CipherSuite: NoiseCipherSuite,
423 Pattern: noise.HandshakeIK,
425 StaticKeypair: noise.DHKey{
426 Private: state.Ctx.Self.NoisePrv[:],
427 Public: state.Ctx.Self.NoisePub[:],
429 PeerStatic: state.Node.NoisePub[:],
431 hs, err := noise.NewHandshakeState(conf)
436 state.payloads = make(chan []byte)
437 state.pings = make(chan struct{})
438 state.infosTheir = make(map[[32]byte]*SPInfo)
439 state.infosOurSeen = make(map[[32]byte]uint8)
440 state.progressBars = make(map[string]struct{})
441 state.started = started
442 state.rxLock = rxLock
443 state.txLock = txLock
445 var infosPayloads [][]byte
446 if !state.listOnly && (state.xxOnly == "" || state.xxOnly == TTx) {
447 infosPayloads = state.Ctx.infosOur(nodeId, state.Nice, &state.infosOurSeen)
449 var firstPayload []byte
450 if len(infosPayloads) > 0 {
451 firstPayload = infosPayloads[0]
453 // Pad first payload, to hide actual number of existing files
454 for i := 0; i < (MaxSPSize-len(firstPayload))/SPHeadOverhead; i++ {
455 firstPayload = append(firstPayload, SPHaltMarshalized...)
460 buf, _, _, err = state.hs.WriteMessage(nil, firstPayload)
465 les := LEs{{"Node", nodeId}, {"Nice", int(state.Nice)}}
466 state.Ctx.LogD("sp-startI", les, func(les LEs) string {
468 "SP with %s (nice %s): sending first message",
470 NicenessFmt(state.Nice),
473 conn.SetWriteDeadline(time.Now().Add(DefaultDeadline)) // #nosec G104
474 if err = state.WriteSP(conn, buf, false); err != nil {
475 state.Ctx.LogE("sp-startI", les, err, func(les LEs) string {
477 "SP with %s (nice %s): writing",
479 NicenessFmt(state.Nice),
485 state.Ctx.LogD("sp-startI-wait", les, func(les LEs) string {
487 "SP with %s (nice %s): waiting for first message",
489 NicenessFmt(state.Nice),
492 conn.SetReadDeadline(time.Now().Add(DefaultDeadline)) // #nosec G104
493 if buf, err = state.ReadSP(conn); err != nil {
494 state.Ctx.LogE("sp-startI-read", les, err, func(les LEs) string {
496 "SP with %s (nice %s): reading",
498 NicenessFmt(state.Nice),
504 payload, state.csOur, state.csTheir, err = state.hs.ReadMessage(nil, buf)
506 state.Ctx.LogE("sp-startI-read", les, err, func(les LEs) string {
508 "SP with %s (nice %s): reading Noise message",
510 NicenessFmt(state.Nice),
516 state.Ctx.LogD("sp-startI-workers", les, func(les LEs) string {
518 "SP with %s (nice %s): starting workers",
520 NicenessFmt(state.Nice),
523 err = state.StartWorkers(conn, infosPayloads, payload)
525 state.Ctx.LogE("sp-startI-workers", les, err, func(les LEs) string {
527 "SP with %s (nice %s): starting workers",
529 NicenessFmt(state.Nice),
537 func (state *SPState) StartR(conn ConnDeadlined) error {
538 started := time.Now()
539 conf := noise.Config{
540 CipherSuite: NoiseCipherSuite,
541 Pattern: noise.HandshakeIK,
543 StaticKeypair: noise.DHKey{
544 Private: state.Ctx.Self.NoisePrv[:],
545 Public: state.Ctx.Self.NoisePub[:],
548 hs, err := noise.NewHandshakeState(conf)
554 state.payloads = make(chan []byte)
555 state.pings = make(chan struct{})
556 state.infosOurSeen = make(map[[32]byte]uint8)
557 state.infosTheir = make(map[[32]byte]*SPInfo)
558 state.progressBars = make(map[string]struct{})
559 state.started = started
560 state.xxOnly = xxOnly
564 logMsg := func(les LEs) string {
566 "SP nice %s: waiting for first message",
567 NicenessFmt(state.Nice),
570 les := LEs{{"Nice", int(state.Nice)}}
571 state.Ctx.LogD("sp-startR", les, logMsg)
572 conn.SetReadDeadline(time.Now().Add(DefaultDeadline)) // #nosec G104
573 if buf, err = state.ReadSP(conn); err != nil {
574 state.Ctx.LogE("sp-startR-read", les, err, logMsg)
577 if payload, _, _, err = state.hs.ReadMessage(nil, buf); err != nil {
578 state.Ctx.LogE("sp-startR-read", les, err, logMsg)
583 for _, n := range state.Ctx.Neigh {
584 if subtle.ConstantTimeCompare(state.hs.PeerStatic(), n.NoisePub[:]) == 1 {
590 peerId := Base32Codec.EncodeToString(state.hs.PeerStatic())
591 err = errors.New("unknown peer: " + peerId)
592 state.Ctx.LogE("sp-startR-unknown", append(les, LE{"Peer", peerId}), err, logMsg)
596 state.rxRate = node.RxRate
597 state.txRate = node.TxRate
598 state.onlineDeadline = node.OnlineDeadline
599 state.maxOnlineTime = node.MaxOnlineTime
600 les = LEs{{"Node", node.Id}, {"Nice", int(state.Nice)}}
602 if err = state.Ctx.ensureRxDir(node.Id); err != nil {
606 if xxOnly == "" || xxOnly == TRx {
607 rxLock, err = state.Ctx.LockDir(node.Id, string(TRx))
612 state.rxLock = rxLock
614 if xxOnly == "" || xxOnly == TTx {
615 txLock, err = state.Ctx.LockDir(node.Id, string(TTx))
620 state.txLock = txLock
622 var infosPayloads [][]byte
623 if xxOnly == "" || xxOnly == TTx {
624 infosPayloads = state.Ctx.infosOur(node.Id, state.Nice, &state.infosOurSeen)
626 var firstPayload []byte
627 if len(infosPayloads) > 0 {
628 firstPayload = infosPayloads[0]
630 // Pad first payload, to hide actual number of existing files
631 for i := 0; i < (MaxSPSize-len(firstPayload))/SPHeadOverhead; i++ {
632 firstPayload = append(firstPayload, SPHaltMarshalized...)
635 state.Ctx.LogD("sp-startR-write", les, func(les LEs) string {
637 "SP with %s (nice %s): sending first message",
638 node.Name, NicenessFmt(state.Nice),
641 buf, state.csTheir, state.csOur, err = state.hs.WriteMessage(nil, firstPayload)
646 conn.SetWriteDeadline(time.Now().Add(DefaultDeadline)) // #nosec G104
647 if err = state.WriteSP(conn, buf, false); err != nil {
648 state.Ctx.LogE("sp-startR-write", les, err, func(les LEs) string {
650 "SP with %s (nice %s): writing",
651 node.Name, NicenessFmt(state.Nice),
657 state.Ctx.LogD("sp-startR-workers", les, func(les LEs) string {
659 "SP with %s (nice %s): starting workers",
660 node.Name, NicenessFmt(state.Nice),
663 err = state.StartWorkers(conn, infosPayloads, payload)
670 func (state *SPState) closeFd(pth string) {
672 if s, exists := state.fds[pth]; exists {
673 delete(state.fds, pth)
676 state.fdsLock.Unlock()
679 func (state *SPState) StartWorkers(
681 infosPayloads [][]byte,
684 les := LEs{{"Node", state.Node.Id}, {"Nice", int(state.Nice)}}
685 state.fds = make(map[string]FdAndFullSize)
686 state.fileHashers = make(map[string]*HasherAndOffset)
687 state.isDead = make(chan struct{})
688 if state.maxOnlineTime > 0 {
689 state.mustFinishAt = state.started.Add(state.maxOnlineTime)
694 queues := spCheckers[*state.Node.Id]
696 queues = &SPCheckerQueues{
697 appeared: make(chan *[32]byte),
698 checked: make(chan *[32]byte),
700 spCheckers[*state.Node.Id] = queues
701 go SPChecker(state.Ctx, state.Node.Id, queues.appeared, queues.checked)
703 state.checkerQueues = *queues
705 for job := range state.Ctx.JobsNoCK(state.Node.Id) {
706 if job.PktEnc.Nice <= state.Nice {
707 state.checkerQueues.appeared <- job.HshValue
713 defer state.wg.Done()
718 case hsh := <-state.checkerQueues.checked:
719 state.payloads <- MarshalSP(SPTypeDone, SPDone{hsh})
725 // Remaining handshake payload sending
726 if len(infosPayloads) > 1 {
729 for _, payload := range infosPayloads[1:] {
731 "sp-queue-remaining",
732 append(les, LE{"Size", int64(len(payload))}),
733 func(les LEs) string {
735 "SP with %s (nice %s): queuing remaining payload (%s)",
736 state.Node.Name, NicenessFmt(state.Nice),
737 humanize.IBytes(uint64(len(payload))),
741 state.payloads <- payload
747 // Processing of first payload and queueing its responses
748 logMsg := func(les LEs) string {
750 "SP with %s (nice %s): processing first payload (%s)",
751 state.Node.Name, NicenessFmt(state.Nice),
752 humanize.IBytes(uint64(len(payload))),
755 state.Ctx.LogD("sp-process", append(les, LE{"Size", int64(len(payload))}), logMsg)
756 replies, err := state.ProcessSP(payload)
758 state.Ctx.LogE("sp-process", les, err, logMsg)
763 for _, reply := range replies {
766 append(les, LE{"Size", int64(len(reply))}),
767 func(les LEs) string {
769 "SP with %s (nice %s): queuing reply (%s)",
770 state.Node.Name, NicenessFmt(state.Nice),
771 humanize.IBytes(uint64(len(payload))),
775 state.payloads <- reply
783 deadlineTicker := time.NewTicker(time.Second)
784 pingTicker := time.NewTicker(PingTimeout)
789 deadlineTicker.Stop()
792 case now := <-deadlineTicker.C:
793 if now.Sub(state.RxLastNonPing) >= state.onlineDeadline &&
794 now.Sub(state.TxLastNonPing) >= state.onlineDeadline {
797 if state.maxOnlineTime > 0 && state.mustFinishAt.Before(now) {
800 if now.Sub(state.RxLastSeen) >= 2*PingTimeout {
806 conn.Close() // #nosec G104
807 case now := <-pingTicker.C:
808 if now.After(state.TxLastSeen.Add(PingTimeout)) {
811 state.pings <- struct{}{}
819 // Spool checker and INFOs sender of appearing files
820 if !state.listOnly && (state.xxOnly == "" || state.xxOnly == TTx) {
823 ticker := time.NewTicker(time.Second)
831 for _, payload := range state.Ctx.infosOur(
838 append(les, LE{"Size", int64(len(payload))}),
839 func(les LEs) string {
841 "SP with %s (nice %s): queuing new info (%s)",
842 state.Node.Name, NicenessFmt(state.Nice),
843 humanize.IBytes(uint64(len(payload))),
847 state.payloads <- payload
858 defer state.SetDead()
859 defer state.wg.Done()
861 if state.NotAlive() {
868 state.Ctx.LogD("sp-got-ping", les, func(les LEs) string {
870 "SP with %s (nice %s): got ping",
871 state.Node.Name, NicenessFmt(state.Nice),
874 payload = SPPingMarshalized
876 case payload = <-state.payloads:
879 append(les, LE{"Size", int64(len(payload))}),
880 func(les LEs) string {
882 "SP with %s (nice %s): got payload (%s)",
883 state.Node.Name, NicenessFmt(state.Nice),
884 humanize.IBytes(uint64(len(payload))),
890 if len(state.queueTheir) == 0 {
892 time.Sleep(100 * time.Millisecond)
895 freq := state.queueTheir[0].freq
897 if state.txRate > 0 {
898 time.Sleep(time.Second / time.Duration(state.txRate))
900 pktName := Base32Codec.EncodeToString(freq.Hash[:])
903 LE{"XX", string(TTx)},
905 LE{"Size", int64(freq.Offset)},
907 logMsg := func(les LEs) string {
909 "SP with %s (nice %s): tx/%s (%s)",
910 state.Node.Name, NicenessFmt(state.Nice),
912 humanize.IBytes(freq.Offset),
915 state.Ctx.LogD("sp-queue", lesp, func(les LEs) string {
916 return logMsg(les) + ": queueing"
918 pth := filepath.Join(
920 state.Node.Id.String(),
922 Base32Codec.EncodeToString(freq.Hash[:]),
924 state.fdsLock.RLock()
925 fdAndFullSize, exists := state.fds[pth]
926 state.fdsLock.RUnlock()
928 fd, err := os.Open(pth)
930 state.Ctx.LogE("sp-queue-open", lesp, err, func(les LEs) string {
931 return logMsg(les) + ": opening"
937 state.Ctx.LogE("sp-queue-stat", lesp, err, func(les LEs) string {
938 return logMsg(les) + ": stating"
942 fdAndFullSize = FdAndFullSize{fd: fd, fullSize: fi.Size()}
944 state.fds[pth] = fdAndFullSize
945 state.fdsLock.Unlock()
947 fd := fdAndFullSize.fd
948 fullSize := fdAndFullSize.fullSize
950 if freq.Offset < uint64(fullSize) {
951 state.Ctx.LogD("sp-file-seek", lesp, func(les LEs) string {
952 return logMsg(les) + ": seeking"
954 if _, err = fd.Seek(int64(freq.Offset), io.SeekStart); err != nil {
955 state.Ctx.LogE("sp-file-seek", lesp, err, func(les LEs) string {
956 return logMsg(les) + ": seeking"
960 buf = make([]byte, MaxSPSize-SPHeadOverhead-SPFileOverhead)
961 n, err := fd.Read(buf)
963 state.Ctx.LogE("sp-file-read", lesp, err, func(les LEs) string {
964 return logMsg(les) + ": reading"
971 LE{"XX", string(TTx)},
973 LE{"Size", int64(n)},
975 state.Ctx.LogD("sp-file-read", lesp, func(les LEs) string {
978 logMsg(les), humanize.IBytes(uint64(n)),
983 payload = MarshalSP(SPTypeFile, SPFile{
988 ourSize := freq.Offset + uint64(len(buf))
991 LE{"XX", string(TTx)},
993 LE{"Size", int64(ourSize)},
994 LE{"FullSize", fullSize},
996 if state.Ctx.ShowPrgrs {
997 state.progressBars[pktName] = struct{}{}
1001 if len(state.queueTheir) > 0 && *state.queueTheir[0].freq.Hash == *freq.Hash {
1002 if ourSize == uint64(fullSize) {
1003 state.Ctx.LogD("sp-file-finished", lesp, func(les LEs) string {
1004 return logMsg(les) + ": finished"
1006 if len(state.queueTheir) > 1 {
1007 state.queueTheir = state.queueTheir[1:]
1009 state.queueTheir = state.queueTheir[:0]
1011 if state.Ctx.ShowPrgrs {
1012 delete(state.progressBars, pktName)
1015 state.queueTheir[0].freq.Offset += uint64(len(buf))
1018 state.Ctx.LogD("sp-file-disappeared", lesp, func(les LEs) string {
1019 return logMsg(les) + ": queue disappeared"
1024 logMsg := func(les LEs) string {
1026 "SP with %s (nice %s): sending %s",
1027 state.Node.Name, NicenessFmt(state.Nice),
1028 humanize.IBytes(uint64(len(payload))),
1031 state.Ctx.LogD("sp-sending", append(les, LE{"Size", int64(len(payload))}), logMsg)
1032 conn.SetWriteDeadline(time.Now().Add(DefaultDeadline)) // #nosec G104
1033 if err := state.WriteSP(conn, state.csOur.Encrypt(nil, nil, payload), ping); err != nil {
1034 state.Ctx.LogE("sp-sending", les, err, logMsg)
1044 if state.NotAlive() {
1047 logMsg := func(les LEs) string {
1049 "SP with %s (nice %s): waiting for payload",
1050 state.Node.Name, NicenessFmt(state.Nice),
1053 state.Ctx.LogD("sp-recv-wait", les, logMsg)
1054 conn.SetReadDeadline(time.Now().Add(DefaultDeadline)) // #nosec G104
1055 payload, err := state.ReadSP(conn)
1060 unmarshalErr := err.(*xdr.UnmarshalError)
1061 if os.IsTimeout(unmarshalErr.Err) {
1064 if unmarshalErr.ErrorCode == xdr.ErrIO {
1067 state.Ctx.LogE("sp-recv-wait", les, err, logMsg)
1070 logMsg = func(les LEs) string {
1072 "SP with %s (nice %s): payload (%s)",
1073 state.Node.Name, NicenessFmt(state.Nice),
1074 humanize.IBytes(uint64(len(payload))),
1079 append(les, LE{"Size", int64(len(payload))}),
1080 func(les LEs) string { return logMsg(les) + ": got" },
1082 payload, err = state.csTheir.Decrypt(nil, nil, payload)
1084 state.Ctx.LogE("sp-recv-got", les, err, func(les LEs) string {
1085 return logMsg(les) + ": got"
1091 append(les, LE{"Size", int64(len(payload))}),
1092 func(les LEs) string {
1093 return logMsg(les) + ": processing"
1096 replies, err := state.ProcessSP(payload)
1098 state.Ctx.LogE("sp-recv-process", les, err, func(les LEs) string {
1099 return logMsg(les) + ": processing"
1105 for _, reply := range replies {
1108 append(les[:len(les)-1], LE{"Size", int64(len(reply))}),
1109 func(les LEs) string {
1111 "SP with %s (nice %s): queuing reply (%s)",
1112 state.Node.Name, NicenessFmt(state.Nice),
1113 humanize.IBytes(uint64(len(reply))),
1117 state.payloads <- reply
1121 if state.rxRate > 0 {
1122 time.Sleep(time.Second / time.Duration(state.rxRate))
1128 conn.Close() // #nosec G104
1134 func (state *SPState) Wait() {
1136 close(state.payloads)
1139 state.Duration = time.Now().Sub(state.started)
1140 state.RxSpeed = state.RxBytes
1141 state.TxSpeed = state.TxBytes
1142 rxDuration := int64(state.RxLastSeen.Sub(state.started).Seconds())
1143 txDuration := int64(state.TxLastSeen.Sub(state.started).Seconds())
1145 state.RxSpeed = state.RxBytes / rxDuration
1148 state.TxSpeed = state.TxBytes / txDuration
1150 for _, s := range state.fds {
1153 for pktName := range state.progressBars {
1154 ProgressKill(pktName)
1158 func (state *SPState) ProcessSP(payload []byte) ([][]byte, error) {
1159 les := LEs{{"Node", state.Node.Id}, {"Nice", int(state.Nice)}}
1160 r := bytes.NewReader(payload)
1162 var replies [][]byte
1165 state.Ctx.LogD("sp-process-unmarshal", les, func(les LEs) string {
1167 "SP with %s (nice %s): unmarshaling header",
1168 state.Node.Name, NicenessFmt(state.Nice),
1172 if _, err = xdr.Unmarshal(r, &head); err != nil {
1173 state.Ctx.LogE("sp-process-unmarshal", les, err, func(les LEs) string {
1175 "SP with %s (nice %s): unmarshaling header",
1176 state.Node.Name, NicenessFmt(state.Nice),
1181 if head.Type != SPTypePing {
1182 state.RxLastNonPing = state.RxLastSeen
1188 append(les, LE{"Type", "halt"}), func(les LEs) string {
1190 "SP with %s (nice %s): got HALT",
1191 state.Node.Name, NicenessFmt(state.Nice),
1196 state.queueTheir = nil
1202 append(les, LE{"Type", "ping"}),
1203 func(les LEs) string {
1205 "SP with %s (nice %s): got PING",
1206 state.Node.Name, NicenessFmt(state.Nice),
1213 lesp := append(les, LE{"Type", "info"})
1215 "sp-process-info-unmarshal", lesp,
1216 func(les LEs) string {
1218 "SP with %s (nice %s): unmarshaling INFO",
1219 state.Node.Name, NicenessFmt(state.Nice),
1224 if _, err = xdr.Unmarshal(r, &info); err != nil {
1226 "sp-process-info-unmarshal", lesp, err,
1227 func(les LEs) string {
1229 "SP with %s (nice %s): unmarshaling INFO",
1230 state.Node.Name, NicenessFmt(state.Nice),
1236 pktName := Base32Codec.EncodeToString(info.Hash[:])
1240 LE{"Size", int64(info.Size)},
1241 LE{"PktNice", int(info.Nice)},
1243 logMsg := func(les LEs) string {
1245 "SP with %s (nice %s): INFO %s (%s) nice %s",
1246 state.Node.Name, NicenessFmt(state.Nice),
1248 humanize.IBytes(info.Size),
1249 NicenessFmt(info.Nice),
1252 if !state.listOnly && info.Nice > state.Nice {
1253 state.Ctx.LogD("sp-process-info-too-nice", lesp, func(les LEs) string {
1254 return logMsg(les) + ": too nice"
1258 state.Ctx.LogD("sp-process-info-got", lesp, func(les LEs) string {
1259 return logMsg(les) + ": received"
1261 if !state.listOnly && state.xxOnly == TTx {
1265 state.infosTheir[*info.Hash] = &info
1267 state.Ctx.LogD("sp-process-info-stat", lesp, func(les LEs) string {
1268 return logMsg(les) + ": stating part"
1270 pktPath := filepath.Join(
1272 state.Node.Id.String(),
1274 Base32Codec.EncodeToString(info.Hash[:]),
1276 logMsg = func(les LEs) string {
1278 "Packet %s (%s) (nice %s)",
1280 humanize.IBytes(info.Size),
1281 NicenessFmt(info.Nice),
1284 if _, err = os.Stat(pktPath); err == nil {
1285 state.Ctx.LogI("sp-info-done", lesp, func(les LEs) string {
1286 return logMsg(les) + ": already done"
1288 if !state.listOnly {
1289 replies = append(replies, MarshalSP(SPTypeDone, SPDone{info.Hash}))
1293 if _, err = os.Stat(pktPath + SeenSuffix); err == nil {
1294 state.Ctx.LogI("sp-info-seen", lesp, func(les LEs) string {
1295 return logMsg(les) + ": already seen"
1297 if !state.listOnly {
1298 replies = append(replies, MarshalSP(SPTypeDone, SPDone{info.Hash}))
1302 if _, err = os.Stat(pktPath + NoCKSuffix); err == nil {
1303 state.Ctx.LogI("sp-info-nock", lesp, func(les LEs) string {
1304 return logMsg(les) + ": still not checksummed"
1308 fi, err := os.Stat(pktPath + PartSuffix)
1313 if !state.Ctx.IsEnoughSpace(int64(info.Size) - offset) {
1314 state.Ctx.LogI("sp-info-no-space", lesp, func(les LEs) string {
1315 return logMsg(les) + ": not enough space"
1321 append(lesp, LE{"Offset", offset}),
1322 func(les LEs) string {
1324 "%s: %d%%", logMsg(les), 100*uint64(offset)/info.Size,
1328 if !state.listOnly && (state.onlyPkts == nil || state.onlyPkts[*info.Hash]) {
1329 replies = append(replies, MarshalSP(
1331 SPFreq{info.Hash, uint64(offset)},
1336 lesp := append(les, LE{"Type", "file"})
1337 state.Ctx.LogD("sp-process-file", lesp, func(les LEs) string {
1339 "SP with %s (nice %s): unmarshaling FILE",
1340 state.Node.Name, NicenessFmt(state.Nice),
1344 if _, err = xdr.Unmarshal(r, &file); err != nil {
1345 state.Ctx.LogE("sp-process-file", lesp, err, func(les LEs) string {
1347 "SP with %s (nice %s): unmarshaling FILE",
1348 state.Node.Name, NicenessFmt(state.Nice),
1353 pktName := Base32Codec.EncodeToString(file.Hash[:])
1356 LE{"XX", string(TRx)},
1358 LE{"Size", int64(len(file.Payload))},
1360 logMsg := func(les LEs) string {
1362 "Got packet %s (%s)",
1363 pktName, humanize.IBytes(uint64(len(file.Payload))),
1366 dirToSync := filepath.Join(
1368 state.Node.Id.String(),
1371 filePath := filepath.Join(dirToSync, pktName)
1372 filePathPart := filePath + PartSuffix
1373 state.Ctx.LogD("sp-file-open", lesp, func(les LEs) string {
1374 return logMsg(les) + ": opening part"
1376 state.fdsLock.RLock()
1377 fdAndFullSize, exists := state.fds[filePathPart]
1378 state.fdsLock.RUnlock()
1381 fd = fdAndFullSize.fd
1383 fd, err = os.OpenFile(
1385 os.O_RDWR|os.O_CREATE,
1389 state.Ctx.LogE("sp-file-open", lesp, err, func(les LEs) string {
1390 return logMsg(les) + ": opening part"
1394 state.fdsLock.Lock()
1395 state.fds[filePathPart] = FdAndFullSize{fd: fd}
1396 state.fdsLock.Unlock()
1397 if file.Offset == 0 {
1398 h, err := blake2b.New256(nil)
1402 state.fileHashers[filePath] = &HasherAndOffset{h: h}
1407 append(lesp, LE{"Offset", file.Offset}),
1408 func(les LEs) string {
1409 return fmt.Sprintf("%s: seeking %d", logMsg(les), file.Offset)
1411 if _, err = fd.Seek(int64(file.Offset), io.SeekStart); err != nil {
1412 state.Ctx.LogE("sp-file-seek", lesp, err, func(les LEs) string {
1413 return logMsg(les) + ": seeking"
1415 state.closeFd(filePathPart)
1418 state.Ctx.LogD("sp-file-write", lesp, func(les LEs) string {
1419 return logMsg(les) + ": writing"
1421 if _, err = fd.Write(file.Payload); err != nil {
1422 state.Ctx.LogE("sp-file-write", lesp, err, func(les LEs) string {
1423 return logMsg(les) + ": writing"
1425 state.closeFd(filePathPart)
1428 hasherAndOffset, hasherExists := state.fileHashers[filePath]
1430 if hasherAndOffset.offset == file.Offset {
1431 if _, err = hasherAndOffset.h.Write(file.Payload); err != nil {
1434 hasherAndOffset.offset += uint64(len(file.Payload))
1437 "sp-file-offset-differs", lesp,
1438 func(les LEs) string {
1439 return logMsg(les) + ": offset differs, deleting hasher"
1442 delete(state.fileHashers, filePath)
1443 hasherExists = false
1446 ourSize := int64(file.Offset + uint64(len(file.Payload)))
1447 lesp[len(lesp)-1].V = ourSize
1448 fullsize := int64(0)
1450 infoTheir, ok := state.infosTheir[*file.Hash]
1453 fullsize = int64(infoTheir.Size)
1455 lesp = append(lesp, LE{"FullSize", fullsize})
1456 if state.Ctx.ShowPrgrs {
1457 state.progressBars[pktName] = struct{}{}
1458 Progress("Rx", lesp)
1460 if fullsize != ourSize {
1463 if state.Ctx.ShowPrgrs {
1464 delete(state.progressBars, pktName)
1466 logMsg = func(les LEs) string {
1468 "Got packet %s %d%% (%s / %s)",
1469 pktName, 100*ourSize/fullsize,
1470 humanize.IBytes(uint64(ourSize)),
1471 humanize.IBytes(uint64(fullsize)),
1476 state.Ctx.LogE("sp-file-sync", lesp, err, func(les LEs) string {
1477 return logMsg(les) + ": syncing"
1479 state.closeFd(filePathPart)
1483 if bytes.Compare(hasherAndOffset.h.Sum(nil), file.Hash[:]) != 0 {
1485 "sp-file-bad-checksum", lesp,
1486 errors.New("checksum mismatch"),
1491 if err = os.Rename(filePathPart, filePath); err != nil {
1492 state.Ctx.LogE("sp-file-rename", lesp, err, func(les LEs) string {
1493 return logMsg(les) + ": renaming"
1497 if err = DirSync(dirToSync); err != nil {
1498 state.Ctx.LogE("sp-file-dirsync", lesp, err, func(les LEs) string {
1499 return logMsg(les) + ": dirsyncing"
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 {
1515 state.closeFd(filePathPart)
1518 if _, err = fd.Seek(0, io.SeekStart); err != nil {
1519 state.Ctx.LogE("sp-file-seek", lesp, err, func(les LEs) string {
1520 return logMsg(les) + ": seeking"
1522 state.closeFd(filePathPart)
1525 _, pktEncRaw, err := state.Ctx.HdrRead(fd)
1526 state.closeFd(filePathPart)
1528 state.Ctx.LogE("sp-file-hdr-read", lesp, err, func(les LEs) string {
1529 return logMsg(les) + ": HdrReading"
1533 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)
1556 state.checkerQueues.appeared <- file.Hash
1560 lesp := append(les, LE{"Type", "done"})
1561 state.Ctx.LogD("sp-process-done-unmarshal", lesp, func(les LEs) string {
1563 "SP with %s (nice %s): unmarshaling DONE",
1564 state.Node.Name, NicenessFmt(state.Nice),
1568 if _, err = xdr.Unmarshal(r, &done); err != nil {
1569 state.Ctx.LogE("sp-process-done-unmarshal", lesp, err, func(les LEs) string {
1571 "SP with %s (nice %s): unmarshaling DONE",
1572 state.Node.Name, NicenessFmt(state.Nice),
1577 pktName := Base32Codec.EncodeToString(done.Hash[:])
1578 lesp = append(lesp, LE{"Pkt", pktName}, LE{"XX", string(TTx)})
1579 logMsg := func(les LEs) string {
1581 "SP with %s (nice %s): DONE: removing %s",
1582 state.Node.Name, NicenessFmt(state.Nice), pktName,
1585 state.Ctx.LogD("sp-done", lesp, logMsg)
1586 pth := filepath.Join(
1588 state.Node.Id.String(),
1592 if err = os.Remove(pth); err == nil {
1593 state.Ctx.LogI("sp-done", lesp, func(les LEs) string {
1594 return fmt.Sprintf("Packet %s is sent", pktName)
1596 if state.Ctx.HdrUsage {
1597 os.Remove(pth + HdrSuffix)
1600 state.Ctx.LogE("sp-done", lesp, err, logMsg)
1604 lesp := append(les, LE{"Type", "freq"})
1605 state.Ctx.LogD("sp-process-freq", lesp, func(les LEs) string {
1607 "SP with %s (nice %s): unmarshaling FREQ",
1608 state.Node.Name, NicenessFmt(state.Nice),
1612 if _, err = xdr.Unmarshal(r, &freq); err != nil {
1613 state.Ctx.LogE("sp-process-freq", lesp, err, func(les LEs) string {
1615 "SP with %s (nice %s): unmarshaling FREQ",
1616 state.Node.Name, NicenessFmt(state.Nice),
1621 pktName := Base32Codec.EncodeToString(freq.Hash[:])
1622 lesp = append(lesp, LE{"Pkt", pktName}, LE{"Offset", freq.Offset})
1623 state.Ctx.LogD("sp-process-freq-queueing", lesp, func(les LEs) string {
1625 "SP with %s (nice %s): FREQ %s: queuing",
1626 state.Node.Name, NicenessFmt(state.Nice), pktName,
1629 nice, exists := state.infosOurSeen[*freq.Hash]
1631 if state.onlyPkts == nil || !state.onlyPkts[*freq.Hash] {
1634 var freqWithNice *FreqWithNice
1635 for insertIdx, freqWithNice = range state.queueTheir {
1636 if freqWithNice.nice > nice {
1640 state.queueTheir = append(state.queueTheir, nil)
1641 copy(state.queueTheir[insertIdx+1:], state.queueTheir[insertIdx:])
1642 state.queueTheir[insertIdx] = &FreqWithNice{&freq, nice}
1645 state.Ctx.LogD("sp-process-freq-skip", lesp, func(les LEs) string {
1647 "SP with %s (nice %s): FREQ %s: skipping",
1648 state.Node.Name, NicenessFmt(state.Nice), pktName,
1653 state.Ctx.LogD("sp-process-freq-unknown", lesp, func(les LEs) string {
1655 "SP with %s (nice %s): FREQ %s: unknown",
1656 state.Node.Name, NicenessFmt(state.Nice), pktName,
1663 "sp-process-type-unknown",
1664 append(les, LE{"Type", head.Type}),
1665 errors.New("unknown type"),
1666 func(les LEs) string {
1668 "SP with %s (nice %s): %d",
1669 state.Node.Name, NicenessFmt(state.Nice), head.Type,
1673 return nil, BadPktType
1681 for _, info := range state.infosTheir {
1686 state.Ctx.LogI("sp-infos-rx", LEs{
1687 {"XX", string(TRx)},
1688 {"Node", state.Node.Id},
1690 {"Size", int64(size)},
1691 }, func(les LEs) string {
1693 "%s has got for us: %d packets, %s",
1694 state.Node.Name, pkts, humanize.IBytes(size),
1698 return payloadsSplit(replies), nil