Skip to content

Commit a5b09f0

Browse files
committed
Some Gossip code refactoring and log msg formatting
1) ToGossipMessage now returns a more meaningful error and the methods that call it now log an error that is based on the context 2) Follow-up fix of a CR comment: https://gerrit.hyperledger.org/r/#/c/5965/13/gossip/comm/comm_impl.go@532 3) selfNetworkMember() accidently logged a log entry that says it is starting a new gossip service, but actually the method is invoked more than once- so multiple messages were logged instead of only one, so I extracted the log invocation to the constructor method. 4) The SignedGossipMessage has a payload which is a byte slice. No reason to log it, so I implemented a String() method for the SignedGossipMessage that just logs the length of the Payload and signature, and of the secret payload. 5) The Payload of the DataMessage that contains a ledger block should be printed as the length of the block and its sequence. I implemented String() method for GossipMessage_DataMsg. 6) Some messages contain a snapshot of envelopes, or payloads and are printed as a slice of tuples of payload (bytes) and signatures (bytes). This is ugly, fills the logs and doesn't give any info. I made the String() of GossipMessage print only the number of items in case it contains such a message. Signed-off-by: Yacov Manevich <[email protected]> Change-Id: Ie59b08ed94ef2f602b36d2ba3ab9b7260bf3f947
1 parent 9a09ac0 commit a5b09f0

File tree

8 files changed

+234
-10
lines changed

8 files changed

+234
-10
lines changed

gossip/comm/comm_impl.go

+4-2
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@ import (
2424
"math/rand"
2525
"net"
2626
"os"
27+
"reflect"
2728
"sync"
2829
"sync/atomic"
2930
"time"
@@ -519,8 +520,7 @@ func readWithTimeout(stream interface{}, timeout time.Duration, address string)
519520
}
520521
incChan <- msg
521522
}
522-
}
523-
if clStr, isClientStr := stream.(proto.Gossip_GossipStreamClient); isClientStr {
523+
} else if clStr, isClientStr := stream.(proto.Gossip_GossipStreamClient); isClientStr {
524524
if m, err := clStr.Recv(); err == nil {
525525
msg, err := m.ToGossipMessage()
526526
if err != nil {
@@ -529,6 +529,8 @@ func readWithTimeout(stream interface{}, timeout time.Duration, address string)
529529
}
530530
incChan <- msg
531531
}
532+
} else {
533+
panic(fmt.Errorf("Stream isn't a GossipStreamServer or a GossipStreamClient, but %v. Aborting", reflect.TypeOf(stream)))
532534
}
533535
}()
534536
select {

gossip/discovery/discovery_impl.go

+2-2
Original file line numberDiff line numberDiff line change
@@ -320,7 +320,7 @@ func (d *gossipDiscoveryImpl) handleMsgFromComm(m *proto.SignedGossipMessage) {
320320
for _, env := range memResp.Alive {
321321
am, err := env.ToGossipMessage()
322322
if err != nil {
323-
d.logger.Warning("Failed extracting GossipMessage from envelope:", err)
323+
d.logger.Warning("Membership response contains an invalid message from an online peer:", err)
324324
return
325325
}
326326
if !am.IsAliveMsg() {
@@ -333,7 +333,7 @@ func (d *gossipDiscoveryImpl) handleMsgFromComm(m *proto.SignedGossipMessage) {
333333
for _, env := range memResp.Dead {
334334
dm, err := env.ToGossipMessage()
335335
if err != nil {
336-
d.logger.Warning("Failed extracting GossipMessage from envelope:", err)
336+
d.logger.Warning("Membership response contains an invalid message from an offline peer", err)
337337
return
338338
}
339339
if !d.crypt.ValidateAliveMsg(m) {

gossip/gossip/certstore.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -78,7 +78,7 @@ func (cs *certStore) handleMessage(msg proto.ReceivedMessage) {
7878
for _, env := range update.Data {
7979
m, err := env.ToGossipMessage()
8080
if err != nil {
81-
cs.logger.Warning("Failed extracting GossipMessage from envelope:", err)
81+
cs.logger.Warning("Data update contains an invalid message:", err)
8282
return
8383
}
8484
if !m.IsIdentityMsg() {

gossip/gossip/channel/channel.go

+2-2
Original file line numberDiff line numberDiff line change
@@ -416,7 +416,7 @@ func (gc *gossipChannel) HandleMessage(msg proto.ReceivedMessage) {
416416
for _, item := range m.GetDataUpdate().Data {
417417
gMsg, err := item.ToGossipMessage()
418418
if err != nil {
419-
gc.logger.Warning("Failed extracting GossipMessage from envelope:", err)
419+
gc.logger.Warning("Data update contains an invalid message:", err)
420420
return
421421
}
422422
if !bytes.Equal(gMsg.Channel, []byte(gc.chainID)) {
@@ -444,7 +444,7 @@ func (gc *gossipChannel) handleStateInfSnapshot(m *proto.GossipMessage, sender c
444444
for _, envelope := range m.GetStateSnapshot().Elements {
445445
stateInf, err := envelope.ToGossipMessage()
446446
if err != nil {
447-
gc.logger.Warning("Failed extracting GossipMessage from envelope:", err)
447+
gc.logger.Warning("StateInfo snapshot contains an invalid message:", err)
448448
return
449449
}
450450
if !stateInf.IsStateInfoMsg() {

gossip/gossip/gossip_impl.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -122,6 +122,7 @@ func NewGossipService(conf *Config, s *grpc.Server, secAdvisor api.SecurityAdvis
122122
g.disSecAdap = g.newDiscoverySecurityAdapter()
123123

124124
g.disc = discovery.NewDiscoveryService(conf.BootstrapPeers, g.selfNetworkMember(), g.discAdapter, g.disSecAdap)
125+
g.logger.Info("Creating gossip service with self membership of", g.selfNetworkMember())
125126

126127
g.certStore = newCertStore(g.createCertStorePuller(), idMapper, selfIdentity, mcs)
127128

@@ -141,7 +142,6 @@ func (g *gossipServiceImpl) selfNetworkMember() discovery.NetworkMember {
141142
Metadata: []byte{},
142143
InternalEndpoint: g.conf.InternalEndpoint,
143144
}
144-
g.logger.Info("Creating gossip service with self membership of", self)
145145
return self
146146
}
147147

gossip/gossip/pull/pullstore.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -156,7 +156,7 @@ func (p *pullMediatorImpl) HandleMessage(m proto.ReceivedMessage) {
156156
for i, pulledMsg := range res.Data {
157157
msg, err := pulledMsg.ToGossipMessage()
158158
if err != nil {
159-
p.logger.Warning("Failed extracting GossipMessage from envelope:", err)
159+
p.logger.Warning("Data update contains an invalid message:", err)
160160
return
161161
}
162162
p.msgCons(msg)

protos/gossip/extensions.go

+74-1
Original file line numberDiff line numberDiff line change
@@ -301,7 +301,13 @@ func (m *GossipMessage) IsTagLegal() error {
301301
return fmt.Errorf("Unknown message type: %v", m)
302302
}
303303

304+
// Verifier receives a peer identity, a signature and a message
305+
// and returns nil if the signature on the message could be verified
306+
// using the given identity.
304307
type Verifier func(peerIdentity []byte, signature, message []byte) error
308+
309+
// Signer signs a message, and returns (signature, nil)
310+
// on success, and nil and an error on failure.
305311
type Signer func(msg []byte) ([]byte, error)
306312

307313
// ReceivedMessage is a GossipMessage wrapper that
@@ -356,6 +362,7 @@ func (m *SignedGossipMessage) Sign(signer Signer) *Envelope {
356362
return e
357363
}
358364

365+
// NoopSign creates a SignedGossipMessage with a nil signature
359366
func (m *GossipMessage) NoopSign() *SignedGossipMessage {
360367
signer := func(msg []byte) ([]byte, error) {
361368
return nil, nil
@@ -397,22 +404,29 @@ func (m *SignedGossipMessage) Verify(peerIdentity []byte, verify Verifier) error
397404
return nil
398405
}
399406

407+
// IsSigned returns whether the message
408+
// has a signature in the envelope.
400409
func (m *SignedGossipMessage) IsSigned() bool {
401410
return m.Envelope != nil && m.Envelope.Payload != nil && m.Envelope.Signature != nil
402411
}
403412

413+
// ToGossipMessage un-marshals a given envelope and creates a
414+
// SignedGossipMessage out of it.
415+
// Returns an error if un-marshaling fails.
404416
func (e *Envelope) ToGossipMessage() (*SignedGossipMessage, error) {
405417
msg := &GossipMessage{}
406418
err := proto.Unmarshal(e.Payload, msg)
407419
if err != nil {
408-
return nil, err
420+
return nil, fmt.Errorf("Failed unmarshaling GossipMessage from envelope: %v", err)
409421
}
410422
return &SignedGossipMessage{
411423
GossipMessage: msg,
412424
Envelope: e,
413425
}, nil
414426
}
415427

428+
// SignSecret signs the secret payload and creates
429+
// a secret envelope out of it.
416430
func (e *Envelope) SignSecret(signer Signer, secret *Secret) {
417431
payload, err := proto.Marshal(secret)
418432
if err != nil {
@@ -428,6 +442,9 @@ func (e *Envelope) SignSecret(signer Signer, secret *Secret) {
428442
}
429443
}
430444

445+
// InternalEndpoint returns the internal endpoint
446+
// in the secret envelope, or an empty string
447+
// if a failure occurs.
431448
func (s *SecretEnvelope) InternalEndpoint() string {
432449
secret := &Secret{}
433450
if err := proto.Unmarshal(s.Payload, secret); err != nil {
@@ -443,6 +460,62 @@ type SignedGossipMessage struct {
443460
*GossipMessage
444461
}
445462

463+
func (p *Payload) toString() string {
464+
return fmt.Sprintf("Block message: {Data: %d bytes, seq: %d}", len(p.Data), p.SeqNum)
465+
}
466+
467+
func (du *DataUpdate) toString() string {
468+
mType := PullMsgType_name[int32(du.MsgType)]
469+
return fmt.Sprintf("Type: %s, items: %d, nonce: %d", mType, len(du.Data), du.Nonce)
470+
}
471+
472+
func (mr *MembershipResponse) toString() string {
473+
return fmt.Sprintf("MembershipResponse with Alive: %d, Dead: %d", len(mr.Alive), len(mr.Dead))
474+
}
475+
476+
func (sis *StateInfoSnapshot) toString() string {
477+
return fmt.Sprintf("StateInfoSnapshot with %d items", len(sis.Elements))
478+
}
479+
480+
// String returns a string representation
481+
// of a SignedGossipMessage
482+
func (m *SignedGossipMessage) String() string {
483+
env := "No envelope"
484+
if m.Envelope != nil {
485+
var secretEnv string
486+
if m.SecretEnvelope != nil {
487+
pl := len(m.SecretEnvelope.Payload)
488+
sl := len(m.SecretEnvelope.Signature)
489+
secretEnv = fmt.Sprintf(" Secret payload: %d bytes, Secret Signature: %d bytes", pl, sl)
490+
}
491+
env = fmt.Sprintf("%d bytes, Signature: %d bytes%s", len(m.Envelope.Payload), len(m.Envelope.Signature), secretEnv)
492+
}
493+
gMsg := "No gossipMessage"
494+
if m.GossipMessage != nil {
495+
var isSimpleMsg bool
496+
if m.GetStateResponse() != nil {
497+
gMsg = fmt.Sprintf("StateResponse with %d items", len(m.GetStateResponse().Payloads))
498+
} else if m.IsDataMsg() {
499+
gMsg = m.GetDataMsg().Payload.toString()
500+
} else if m.IsDataUpdate() {
501+
update := m.GetDataUpdate()
502+
gMsg = fmt.Sprintf("DataUpdate: %s", update.toString())
503+
} else if m.GetMemRes() != nil {
504+
gMsg = m.GetMemRes().toString()
505+
} else if m.IsStateInfoSnapshot() {
506+
gMsg = m.GetStateSnapshot().toString()
507+
} else {
508+
gMsg = m.GossipMessage.String()
509+
isSimpleMsg = true
510+
}
511+
if !isSimpleMsg {
512+
desc := fmt.Sprintf("Channel: %v, nonce: %d, tag: %s", m.Channel, m.Nonce, GossipMessage_Tag_name[int32(m.Tag)])
513+
gMsg = fmt.Sprintf("%s %s", desc, gMsg)
514+
}
515+
}
516+
return fmt.Sprintf("GossipMessage: %v, Envelope: %s", gMsg, env)
517+
}
518+
446519
// Abs returns abs(a-b)
447520
func abs(a, b uint64) uint64 {
448521
if a > b {

protos/gossip/extensions_test.go

+149
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,149 @@
1+
/*
2+
Copyright IBM Corp. 2017 All Rights Reserved.
3+
4+
Licensed under the Apache License, Version 2.0 (the "License");
5+
you may not use this file except in compliance with the License.
6+
You may obtain a copy of the License at
7+
8+
http://www.apache.org/licenses/LICENSE-2.0
9+
10+
Unless required by applicable law or agreed to in writing, software
11+
distributed under the License is distributed on an "AS IS" BASIS,
12+
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
See the License for the specific language governing permissions and
14+
limitations under the License.
15+
*/
16+
17+
package gossip
18+
19+
import (
20+
"fmt"
21+
"testing"
22+
23+
"github.com/stretchr/testify/assert"
24+
)
25+
26+
func TestToString(t *testing.T) {
27+
// Ensure we don't print the byte content when we
28+
// log messages.
29+
// Each payload or signature contains '2' so we would've logged
30+
// them if not for the overloading of the String() method in SignedGossipMessage
31+
32+
// The following line proves that the envelopes constructed in this test
33+
// have "2" in them when they are printed
34+
assert.Contains(t, fmt.Sprintf("%v", envelopes()[0]), "2")
35+
// and the following does the same for payloads:
36+
dMsg := &DataMessage{
37+
Payload: &Payload{
38+
SeqNum: 3,
39+
Data: []byte{2, 2, 2, 2, 2},
40+
},
41+
}
42+
assert.Contains(t, fmt.Sprintf("%v", dMsg), "2")
43+
44+
// Now we construct all types of messages that have envelopes or payloads in them
45+
// and see that "2" is not outputted into their formatting even though it is found
46+
// as a sub-message of the outer message.
47+
48+
sMsg := &SignedGossipMessage{
49+
GossipMessage: &GossipMessage{
50+
Tag: GossipMessage_EMPTY,
51+
Nonce: 5,
52+
Channel: []byte("A"),
53+
Content: &GossipMessage_DataMsg{
54+
DataMsg: &DataMessage{
55+
Payload: &Payload{
56+
SeqNum: 3,
57+
Data: []byte{2, 2, 2, 2, 2},
58+
},
59+
},
60+
},
61+
},
62+
Envelope: &Envelope{
63+
Payload: []byte{0, 1, 2, 3, 4, 5, 6},
64+
Signature: []byte{0, 1, 2},
65+
SecretEnvelope: &SecretEnvelope{
66+
Payload: []byte{0, 1, 2, 3, 4, 5},
67+
Signature: []byte{0, 1, 2},
68+
},
69+
},
70+
}
71+
assert.NotContains(t, fmt.Sprintf("%v", sMsg), "2")
72+
73+
sMsg = &SignedGossipMessage{
74+
GossipMessage: &GossipMessage{
75+
Channel: []byte("A"),
76+
Tag: GossipMessage_EMPTY,
77+
Nonce: 5,
78+
Content: &GossipMessage_DataUpdate{
79+
DataUpdate: &DataUpdate{
80+
Nonce: 11,
81+
MsgType: PullMsgType_BlockMessage,
82+
Data: envelopes(),
83+
},
84+
},
85+
},
86+
Envelope: envelopes()[0],
87+
}
88+
assert.NotContains(t, fmt.Sprintf("%v", sMsg), "2")
89+
90+
sMsg = &SignedGossipMessage{
91+
GossipMessage: &GossipMessage{
92+
Channel: []byte("A"),
93+
Tag: GossipMessage_EMPTY,
94+
Nonce: 5,
95+
Content: &GossipMessage_MemRes{
96+
MemRes: &MembershipResponse{
97+
Alive: envelopes(),
98+
Dead: envelopes(),
99+
},
100+
},
101+
},
102+
Envelope: envelopes()[0],
103+
}
104+
assert.NotContains(t, fmt.Sprintf("%v", sMsg), "2")
105+
106+
sMsg = &SignedGossipMessage{
107+
GossipMessage: &GossipMessage{
108+
Channel: []byte("A"),
109+
Tag: GossipMessage_EMPTY,
110+
Nonce: 5,
111+
Content: &GossipMessage_StateSnapshot{
112+
StateSnapshot: &StateInfoSnapshot{
113+
Elements: envelopes(),
114+
},
115+
},
116+
},
117+
Envelope: envelopes()[0],
118+
}
119+
assert.NotContains(t, fmt.Sprintf("%v", sMsg), "2")
120+
121+
sMsg = &SignedGossipMessage{
122+
GossipMessage: &GossipMessage{
123+
Channel: []byte("A"),
124+
Tag: GossipMessage_EMPTY,
125+
Nonce: 5,
126+
Content: &GossipMessage_StateResponse{
127+
StateResponse: &RemoteStateResponse{
128+
Payloads: []*Payload{
129+
{Data: []byte{2, 2, 2}},
130+
},
131+
},
132+
},
133+
},
134+
Envelope: envelopes()[0],
135+
}
136+
assert.NotContains(t, fmt.Sprintf("%v", sMsg), "2")
137+
}
138+
139+
func envelopes() []*Envelope {
140+
return []*Envelope{
141+
{Payload: []byte{2, 2, 2},
142+
Signature: []byte{2, 2, 2},
143+
SecretEnvelope: &SecretEnvelope{
144+
Payload: []byte{2, 2, 2},
145+
Signature: []byte{2, 2, 2},
146+
},
147+
},
148+
}
149+
}

0 commit comments

Comments
 (0)