gnmi_collector with tunnel_request option is not communicating with tunnel client running on target

[aagrawal493]

Hi,

Objective :- try to see working of grpctunnel using gnmi_collector with tunnel_request option and example client code.
gnmi_collector (running on host machine ) <----> grpctunnel client on NE --------> C++ grpc server on NE

Issue :-
On host machine gnmi_collector with tunnel_request option following command has been used
./gnmi_collector -port 50052 -v 1 -tunnel_request "true" -config_file ./testdata/iqnos.cfg -cert_file ./testdata/selfsigned.crt -key_file ./testdata/selfsigned.key -stderrthreshold 6 -v 6 -logtostderr

target machine is running with tunnel client example given in grpctunnel package using (tunnelAddress configured as host machine ip)
At client side register rpc is called and and further Target and Subscribe messages has been received from gnmi_collector.
Peer target also has been added both side tunnel client as well as gnmi_collector side.
gnmi_collector side addTargetHandler is called and target has been added after running tunnel client.

But now further gnmi_collector is not sending any NewSession request towards tunnel client , because of that gnmi_collector as well as tunnel client both are stuck.

gnmi_collector is waiting in select for one of case to happen ie. inside
func (c *collector) start(ctx context.Context) {

case target := <-c.chAddTarget: or case target := <-c.chDeleteTarget:

}

Following configuration file has been used.
cat ./testdata/iqnos.cfg
request: <
key: "interfaces"
value: <
subscribe: <
prefix: <
origin: "openconfig"
>
subscription: <
path: <
elem: <
name: "oc-if:interfaces"
>
elem: <
name: "oc-if:interface"
key: <
key: "name"
value: "GIGECLIENTCTP.2-*"
>
>
>
>
>

target: <
key: "TARGET1"
value: <
addresses: ":50052"
request: "interfaces"
credentials: <
username: "username"
password: "some password"
>

Can someone suggest what i am missing here or is it a problem ?

Thanks

[jxx-gg]

When c.addTargetHandler is called, it will pass the target to the channel c.chAddTarget, which is expected to be picked up by by the goroutine in c.start. Here it monitors the c.chAddTarget channel and should create a tunnel session. You probably want to check whether the target in the handler is picked up in the c.start and if there is any error before NewSession (via tunnel.ServerConn) is called.

[aagrawal493]

Thanks for pointing it , i see that i was getting error in addTargetHandler , as i had given Target id same in gnmi_collector configuration file as well as tunnel client side target id.
When i made now target id different then i can see gnmi_collector is sending NewSession request, but now it is throwing error for nil query though i am running now tunnel_request with query as below command

NewQuery(%s): %v input is nil

./gnmi_collector -port 50052 -v 4 -tunnel_request "/oc-if:interfaces/oc-if:interface[name=GIGECLIENTCTP.2-*]" -config_file ./testdata/iqnos.cfg -cert_file ./testdata/selfsigned.crt -key_file ./testdata/selfsigned.key -stderrthreshold 6 -v 6 -logtostderr

once New Session is requested from gnmi_collector to tunnel client
it should send this "/oc-if:interfaces/oc-if:interface[name=GIGECLIENTCTP.2-*]" request to tunnel client running on NE.

[jxx-gg]

Are you able to check what is passed into the client.NewQuery? In start you can see that target is passed to runSingleTarget, which should contains the request.

[aagrawal493]

Yes i already checked that , qr := c.config.Request[target.Request] before this line i printed target.Request which is
printing as "/oc-if:interfaces/oc-if:interface[name=GIGECLIENTCTP.2-*]" but once this line is executed, i printed qr.String() that is Nill,
Is it because this Request should be in certain format ?

[gcsl]

The request should be a named request in your config file as it gets added to a Tunnel target dynamically.
The tunnel request commandline gets added to a tunnel target here
https://github.com/openconfig/gnmi/blob/master/cmd/gnmi_collector/gnmi_collector.go#L341
Which is this field from the config file
https://github.com/openconfig/gnmi/blob/master/proto/target/target.proto#L60
which references a config request via this map
https://github.com/openconfig/gnmi/blob/master/proto/target/target.proto#L34

[aagrawal493]

thanks for information, after providing named request which is present in gnmi_collector config file, i see that Request is sent toward tunnel_client side, but immediately connection is getting closed , i have enabled
GODEBUG=http2debug=2 GRPC_VERBOSITY=info GRPC_TRACE=http,api these logs, it seems to me gnmi_collector is terminating connection immediately.

gnmi_collector logs

I0318 09:42:17.021600 8233 register.go:113] Attempting client types: [gnmi]
2021/03/18 09:42:17 http2: Framer 0xa91c580: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote HEADERS flags=END_HEADERS stream=3 len=2
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote DATA stream=3 len=282 data="\x00\x00\x00\x01\x15\x12\x92\x02\x16\x03\x01\x01\r\x01\x00\x01\t\x03\x03\xed\x1e]\x99,\xe56\x8f]\x12\xd0\xe7\xe0\x82\x00\xc2\xdf\xf5b\x13YnB\xfc;\v\xe1\x9d\xc1\xef@m \u007f\xa5!\x9cuWZ$\x9b/s\x98\u007fùrJ\x01õ\xc7^\xb9_F\x16\x1c]\x00\xce\xc4A\x00&\xc0/\xc00\xc0+\xc0,̨̩\xc0\x13\xc0\t\xc0\x14\xc0\n\x00\x9c\x00\x9d\x00/\x005\xc0\x12\x00\n\x13\x01\x13\x03\x13\x02\x01\x00\x00\x9a3t\x00\x00\x00\x00\x00\x0e\x00\f\x00\x00\tlocalhost\x00\x05\x00\x05\x01\x00\x00\x00\x00\x00\n\x00\n\x00\b\x00\x1d\x00\x17\x00\x18\x00\x19\x00\v\x00\x02\x01\x00\x00\r\x00\x1a\x00\x18\b\x04\x04\x03\b\a\b\x05\b\x06\x04\x01\x05\x01\x06\x01\x05\x03\x06\x03\x02\x01\x02\x03\xff\x01\x00\x01\x00\x00\x10\x00\x05\x00\x03\x02h2\x00\x12\x00\x00\x00+\x00\t\b\x03\x04\x03\x03\x03\x02\x03\x01\x003\x00&\x00$\x00\x1d\x00 \vv\x04\xeb\xa0\v" (26 bytes omitted)
2021/03/18 09:42:17 http2: Framer 0xa91c580: read DATA stream=3 len=41 data="\x00\x00\x00\x00$\x12"\x00\x00\f\x04\x00\x00\x00\x00\x00\x00\x04\x00\x00\xff\xff\x00\x06\x00\x00@\x00\x00\x00\x04\b\x00\x00\x00\x00\x00\x00\x0f\x00\x01"
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote WINDOW_UPDATE len=4 (conn) incr=41
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote DATA stream=3 len=7 data="\x00\x00\x00\x00\x02\x18\x01"
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote DATA stream=3 len=7 data="\x00\x00\x00\x00\x02\x18\x01"
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote HEADERS flags=END_STREAM|END_HEADERS stream=3 len=24
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote RST_STREAM stream=3 len=4 ErrCode=NO_ERROR
2021/03/18 09:42:17 http2: Framer 0xa91c580: read WINDOW_UPDATE len=4 (conn) incr=304
2021/03/18 09:42:17 http2: Framer 0xa91c580: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 09:42:17 http2: Framer 0xa91c580: read DATA stream=3 len=7 data="\x00\x00\x00\x00\x02\x18\x01"
2021/03/18 09:42:17 http2: Framer 0xa91c580: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 09:42:17 http2: Framer 0xa91c580: read RST_STREAM stream=3 len=4 ErrCode=NO_ERROR
2021/03/18 09:42:17 http2: Framer 0xa91c580: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
NewImpl failed %v
client "gnmi" : Dialer(localhost:50052, 1m0s): context deadline exceeded
Subscribe failed for target %q: %v TARGET1 client "gnmi" : client "gnmi" : Dialer(localhost:50052, 1m0s): context deadline exceeded
target %s removed TARGET1
^C

tunnel_client logs

2021/03/18 04:39:04 http2: Framer 0xac80580: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote WINDOW_UPDATE len=4 (conn) incr=29
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote HEADERS flags=END_HEADERS stream=3 len=27
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote DATA stream=3 len=7 data="\x00\x00\x00\x00\x02\b\x01"
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote DATA stream=3 len=41 data="\x00\x00\x00\x00$\x12"\x00\x00\f\x04\x00\x00\x00\x00\x00\x00\x04\x00\x00\xff\xff\x00\x06\x00\x00@\x00\x00\x00\x04\b\x00\x00\x00\x00\x00\x00\x0f\x00\x01"
2021/03/18 04:39:04 http2: Framer 0xac80580: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 04:39:04 http2: Framer 0xac80580: read WINDOW_UPDATE len=4 (conn) incr=27
2021/03/18 04:39:04 http2: Framer 0xac80580: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 04:39:04 http2: Framer 0xac80580: read HEADERS flags=END_HEADERS stream=3 len=2
2021/03/18 04:39:04 http2: decoded hpack field header field ":status" = "200"
2021/03/18 04:39:04 http2: decoded hpack field header field "content-type" = "application/grpc"
2021/03/18 04:39:04 http2: Framer 0xac80580: read DATA stream=3 len=282 data="\x00\x00\x00\x01\x15\x12\x92\x02\x16\x03\x01\x01\r\x01\x00\x01\t\x03\x03\xab\xe8naQ\xab\xec\xf6\xc0\xa8mY\x8bB(k\xe5\xf9V\xabtԡ\x05\xac\xdeΎ\xeaZ]\xb4 \x12\x9f\x9e\x9e\x95)!V|S|\x85\xaed~A\x8aH) _\xf9_8\xbc\xdbs\xe9\xe4\f\xf0G\x00&\xc0/\xc00\xc0+\xc0,̨̩\xc0\x13\xc0\t\xc0\x14\xc0\n\x00\x9c\x00\x9d\x00/\x005\xc0\x12\x00\n\x13\x01\x13\x03\x13\x02\x01\x00\x00\x9a3t\x00\x00\x00\x00\x00\x0e\x00\f\x00\x00\tlocalhost\x00\x05\x00\x05\x01\x00\x00\x00\x00\x00\n\x00\n\x00\b\x00\x1d\x00\x17\x00\x18\x00\x19\x00\v\x00\x02\x01\x00\x00\r\x00\x1a\x00\x18\b\x04\x04\x03\b\a\b\x05\b\x06\x04\x01\x05\x01\x06\x01\x05\x03\x06\x03\x02\x01\x02\x03\xff\x01\x00\x01\x00\x00\x10\x00\x05\x00\x03\x02h2\x00\x12\x00\x00\x00+\x00\t\b\x03\x04\x03\x03\x03\x02\x03\x01\x003\x00&\x00$\x00\x1d\x00 \a7\xf7B\xa1\x00" (26 bytes omitted)
2021/03/18 04:39:04 http2: Framer 0xac80580: read DATA stream=3 len=7 data="\x00\x00\x00\x00\x02\x18\x01"
2021/03/18 04:39:04 http2: Framer 0xac80580: read DATA stream=3 len=7 data="\x00\x00\x00\x00\x02\x18\x01"
2021/03/18 04:39:04 http2: Framer 0xac80580: read HEADERS flags=END_STREAM|END_HEADERS stream=3 len=24
2021/03/18 04:39:04 http2: decoded hpack field header field "grpc-status" = "0"
2021/03/18 04:39:04 http2: decoded hpack field header field "grpc-message" = ""
2021/03/18 04:39:04 http2: Framer 0xac80580: read RST_STREAM stream=3 len=4 ErrCode=NO_ERROR
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote WINDOW_UPDATE len=4 (conn) incr=364
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2021/03/18 04:39:04 http2: Framer 0xac80580: wrote RST_STREAM stream=3 len=4 ErrCode=NO_ERROR
2021/03/18 04:39:04 http2: Framer 0xac80580: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"

my internal grpc server is running on port 50051 on NE i see that there connection is going for timewait

netstat -an | grep -i 50051
tcp 0 0 ::ffff:127.0.0.1:50051 :::* LISTEN
tcp 0 0 ::ffff:127.0.0.1:50051 ::ffff:127.0.0.1:38824 TIME_WAIT

[aagrawal493]

I looked further and i see that at grpcserver side, i am getting following message in debug logs
"grpc-message: USERNAME/PASSWORD Field(s) are Not Specified"

For tunnel request as command line option only name request needs to be given , so can someone suggest how to pass username and password also for authentication.

[jxx-gg]

Are you able to test grpc-tunnel and gnmi-collector separately to see if they are working? Does the client (grpc server) require login?

[aagrawal493]

yes i am able to test grpc-tunnel and gnmi-collector seperately,
Yes grpc server requires username/password authentication.
i have given named request (which is present in configuration file) as tunnel_request option, while running gnmi_collector. but i am not able to find how to provide username/password at gnmi_collector side , for same request.

[jxx-gg]

The grpc tunnel hands over the connection to the collector/target once its server/client connection is established. We should expect all the operations following that unchanged compared to the case without the tunnel. I am afraid that I don't have knowledge about your target (grpc server), so cannot comment on that. I suggest find the place where the tunnel session is handled on the target side (possibly on the collector side as well), and make sure the tunnel is up.

[jxx-gg]

After a closer look, I might have misunderstood your question. When using the tunnel, you probably can add the credential in collector.addTarget, which is used to construct the target when it receives a target from collector.chAddTarget.

[aagrawal493]

i tried it adding in cfg file , which is read by gnmi_collector, in following format.

target: <
key: "TARGET2"
value: <
addresses: "x.y.z.w:50052"
request: "interfaces"
credentials: <
username: "username"
password: "password"
>

but if i do so , then this target is considered as dial in target in gnmi_collector, and dialin request goes for this target.
I tried to give credential without target name, but that is also not possible.
So my question is for tunnel connection, when add target request is coming , then from where credentials should be read,
My understanding says it should be read somehow from this config file only.
Or are u suggesting that credential information should be sent from tunnel client itself ?

[jxx-gg]

For testing, you can just add the credential in collector.addTarget, e.g., by passing a target_password/username flags.

As you have more targets to collect from, I image that you probably need to add the credentials to a config, but here you will need to distinguish the targets fully configured in the file vs those only configured for their credentials. Think you will need to add additional logic for that.

For security purpose, sending credential form tunnel client defers its purpose.