Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

panic: WaitForFunc failed #30

Open
songtianyi opened this issue May 15, 2017 · 26 comments
Open

panic: WaitForFunc failed #30

songtianyi opened this issue May 15, 2017 · 26 comments
Assignees
Labels

Comments

@songtianyi
Copy link

It paniced when i execute rpc in a single session.

package main

import (
	"fmt"
	"golang.org/x/crypto/ssh"
	"log"

	"github.com/Juniper/go-netconf/netconf"
)

func doRpc(s *netconf.Session, xml string) {
	reply, err := s.Exec(netconf.RawMethod(xml))
	if err != nil {
		panic(err)
	}
	fmt.Printf("Reply: %+v", reply)
}

func main() {
	sshConfig := &ssh.ClientConfig{
		User: "root",
		Auth: []ssh.AuthMethod{ssh.Password("r00ttest")},
		HostKeyCallback: ssh.InsecureIgnoreHostKey(),
	}

	s, err := netconf.DialSSH("172.16.240.189", sshConfig)

	if err != nil {
		log.Fatal(err)
	}

	defer s.Close()

	fmt.Println(s.ServerCapabilities)
	fmt.Println(s.SessionID)

	//xml := "<get-config><source><running/></source></get-config>"
	xml := "<rpc><edit-config><target>candidate</target><system><host-name>hehe</host-name></system></edit-config></rpc>"

	// Sends raw XML
	doRpc(s, xml)
	xml = "<rpc></commit></rpc>"
	doRpc(s, xml)
}
@jhollar
Copy link

jhollar commented May 24, 2017

any update on this issue?

@nemith
Copy link
Collaborator

nemith commented May 24, 2017

Do you have the panic stacktrace?

@jhollar
Copy link

jhollar commented May 24, 2017

Yes,
FAILURE:
2017/05/24 13:05:33 WaitForFunc failed
exit status 1
On NSO, I actually see the connection.
netconf id=25 new ssh session for user "vmsnso" from

@nemith
Copy link
Collaborator

nemith commented May 24, 2017

Also usually netconf runs on a different port on Junos. 830 by default

See https://www.juniper.net/documentation/en_US/junos/topics/topic-map/netconf-ssh-connection.html

@jhollar
Copy link

jhollar commented May 24, 2017

yea, I'm connecting on port 830

@nemith
Copy link
Collaborator

nemith commented May 24, 2017

Odd. WaitForFunc should never be called.

@jhollar
Copy link

jhollar commented May 24, 2017

Here's what I'm using
s, err := netconf.DialSSHTimeout("...:830", sshConfig, duration_Milliseconds)

@mislavn
Copy link

mislavn commented May 24, 2017

I had a similar problem but the same error message. The problem on my side surfaced while using Netopeer2, by default Netopeer2 server closes the ssh connection after 20 seconds of inactivity. So if I used a session after being inactive/waiting for 20 seconds I would get "WaitForFunc failed".

Would it help if I send you a dockerfile and a bash script which would reproduce the bug?

@jhollar
Copy link

jhollar commented May 24, 2017

Yes, that would be helpful at least to help isolate the problem

@mislavn
Copy link

mislavn commented May 25, 2017

Pull and run the docker container with Netopeer2.

docker pull sysrepo/sysrepo-netopeer2:latest
docker run -p 830:830 --name sysrepo --rm sysrepo/sysrepo-netopeer2:latest

The go code.

package main

import (
	"fmt"
	"log"
	"time"

	"github.com/sartura/go-netconf/netconf"
)

func main() {
	auth := netconf.SSHConfigPassword("netconf", string("netconf"))
	s, err := netconf.DialSSH("localhost", auth)
	if err != nil {
		log.Fatal(err)
	}

	defer s.Close()

	fmt.Println(s.ServerCapabilities)
	fmt.Println(s.SessionID)

	time.Sleep(21 * time.Second)

	// Sends raw XML
	reply, err := s.Exec(netconf.MethodGetConfig("startup"))
	if err != nil {
		panic(err)
	}
	fmt.Printf("Reply: %+v", reply)
}

If you comment out time.Sleep(21 * time.Second) the code will work.

Also one quick note, I used go-netconf from the sartura repository becaus it has the two patches that are needed for working with Netopeer2. They are in the pull request #25. If you use github.com/Juniper/go-netconf/netconf you will get WaitForFunc failed.

If you need any further assistance please let me know.

@emasean
Copy link

emasean commented Nov 8, 2017

For me this issue seems has nothing to do with remote peer resetting the connection (like Netopeer2), verifying tcpdump on port 830 I can see that there is no network activity when encountering this issue during the very first RPC send (the session can be established successfully). The SSH TCP connection on port 830 is intact when it happens.

@emasean
Copy link

emasean commented Nov 8, 2017

Used github.com/sartura/go-netconf/netconf and it worked right away. I am actually not using Netopeer2 as Netconf server. so this issue seems to be more widespread than just for Netopeer2.

@eriksejr
Copy link

Exec() calls transport.Receive() which calls WaitForBytes() which calls WaitForFunc()

This panic seems to be the result of getting a message back from the netconf server which does not end with the expected message separator. WaitForFunc() will read an EOF and break the loop, causing the panic/error. Once way to patch it would be something like this:

func (t *transportBasicIO) WaitForFunc(f func([]byte) (int, error)) ([]byte, error) {
	var out bytes.Buffer
	buf := make([]byte, 4096)
	pos := 0
	for {
		n, err := t.Read(buf[pos : pos+(len(buf)/2)])
		if err != nil {
			if err != io.EOF {
				return nil, err
			}
			// Handle EOF but no message separator to mark
			// the end of the message
			if n == 0 {
				out.Write(buf[0:pos])
				return out.Bytes(), nil
			}
			break
		}
		if n > 0 {
			end, err := f(buf[0 : pos+n])
			if err != nil {
				return nil, err
			}
			if end > -1 {
				out.Write(buf[0:end])
				return out.Bytes(), nil
			}
			if pos > 0 {
				out.Write(buf[0:pos])
				copy(buf, buf[pos:pos+n])
			}
			pos = n
		}
	}
	return nil, fmt.Errorf("WaitForFunc failed")
}

At the very least the error returned from the server should now come back in the reply. Its not likely to be a valid netconf message though. The error handling needs to be improved.

@mjoshiNetElastic
Copy link

Even after I applied this patch, the problem is that subsequent operations also fail with the same error. Do I need to reset the session connection?

@eriksejr
Copy link

eriksejr commented Jan 31, 2018

I'm afraid I'm unable to spend a lot of time helping to debug your specific problem with the package. In my experience with this its likely you are not even getting a valid netconf response from the server. Did you dump the response message to confirm the server is not returning an error?

You can enable debug logging in the package by including the standard lib log package and adding something like this to the top of your code before making any calls to go-netconf:

ncLogger := netconf.NewStdLog(log.New(os.Stdout, "NCDEBUG", log.Lshortfile), netconf.LogDebug)
netconf.SetLog(ncLogger)

I also noticed that the default capabilities string defined in transport.go for this package seems to contradict RFC 4741. In transport.go we have:

var DefaultCapabilities = []string{
	"urn:ietf:params:xml:ns:netconf:base:1.0",
}

While in the RFC it indicates the string should be:

var DefaultCapabilities = []string{
	"urn:ietf:params:netconf:base:1.0",
}

The server I was using returned an error until that was corrected. It also required some namespaces which I hacked in - you can see them by looking at the fork in my repo. Its not pretty but it worked for me.

I hope this helps you to resolve your problem. I appreciate the original authors work on this package but it is unfortunate he was not able to finish it.

@mjoshiNetElastic
Copy link

thanks for the inputs @eriksejr . I still do see this issue with all the mods suggested. For now, I have resorted to resetting the client connection when I see this error.

@damianoneill
Copy link
Contributor

@eriksejr I dont see netconf.NewStdLog can you confirm this is available in the public release?

Thanks,
Damian.

@eriksejr
Copy link

@damianoneill I believe the developer who has taken over this project removed or re-wrote the logging code in one of his commits. So this method of enabling the logging is no longer valid.

@damianoneill
Copy link
Contributor

Just noticed it seems to be a function of v0.1 not v0.1.1.

Can someone explain the difference between these two version?

@damianoneill
Copy link
Contributor

@eriksejr thanks for the reply.

@GIC-de The reason for asking about the logging, I am seeing the same issue with WaitForFunc error being propagated. I have a client connecting to a Device which I know to be running netopeer2.

I am creating a connection and keeping this open, I send repeated get / get-config operations with no delay down the connection to place it under load. After a small number of requests ~10 I get the WaitForFunc error propagated, all further calls to the session result in the same error.

Has anyone seen similiar behaviour?

On the logging of payloads, this would seem a useful feature? Is it supported any other way?

@GIC-de GIC-de self-assigned this Jun 22, 2018
@GIC-de
Copy link
Contributor

GIC-de commented Jun 22, 2018

The WaitForFunc failed error is caused only if read returns EOF which should be the case if the session was closed only. I would propose to change the error message to session closed.

The original code from this issue is reproducible if tested against JunOS. In this case JunOS closes the the session caused by malformed/invalid rpc.

@nemith
Copy link
Collaborator

nemith commented Jul 22, 2022

I think this has been fixed. Either way this is pretty old. Going to close for now.

@nemith nemith closed this as completed Jul 22, 2022
inspiregates added a commit to inspiregates/go-netconf that referenced this issue Feb 17, 2023
@inspiregates
Copy link

This has not been fixed and is reproducible with Junos 21.2R0 image on a vSRX platform. Appreciate considering #30 (comment) that helps distinguish between EOF and missing expected separator.

@nemith
Copy link
Collaborator

nemith commented Feb 18, 2023

There is a lot wrong with this code. Juniper has pretty much abandoned this project (I haven't worked for juniper for almost a decade now). I have started work on a rewrite, but I would accept not breaking PRs.

@nemith nemith reopened this Feb 18, 2023
@inspiregates
Copy link

inspiregates commented Feb 22, 2023

@eriksejr are you interested in submitting a PR with your suggested fix? I am glad it helped a bit and it didn't break anything.

@eriksejr
Copy link

@inspiregates Thanks for the offer. I think I did this so informally because it was more of a hack job and I no longer use this code for anything nor do I have access to anything to test it against. So I'm afraid I have no more to offer this project at this time.

nemith pushed a commit that referenced this issue Apr 4, 2023
…6.0 (#30)

Bumps [golang.org/x/crypto](https://github.com/golang/crypto) from
0.0.0-20221010152910-d6f0a8c073c2 to 0.6.0.
<details>
<summary>Commits</summary>
<ul>
<li>See full diff in <a
href="https://github.com/golang/crypto/commits/v0.6.0">compare
view</a></li>
</ul>
</details>
<br />


[![Dependabot compatibility
score](https://dependabot-badges.githubapp.com/badges/compatibility_score?dependency-name=golang.org/x/crypto&package-manager=go_modules&previous-version=0.0.0-20221010152910-d6f0a8c073c2&new-version=0.6.0)](https://docs.github.com/en/github/managing-security-vulnerabilities/about-dependabot-security-updates#about-compatibility-scores)

Dependabot will resolve any conflicts with this PR as long as you don't
alter it yourself. You can also trigger a rebase manually by commenting
`@dependabot rebase`.

[//]: # (dependabot-automerge-start)
[//]: # (dependabot-automerge-end)

---

<details>
<summary>Dependabot commands and options</summary>
<br />

You can trigger Dependabot actions by commenting on this PR:
- `@dependabot rebase` will rebase this PR
- `@dependabot recreate` will recreate this PR, overwriting any edits
that have been made to it
- `@dependabot merge` will merge this PR after your CI passes on it
- `@dependabot squash and merge` will squash and merge this PR after
your CI passes on it
- `@dependabot cancel merge` will cancel a previously requested merge
and block automerging
- `@dependabot reopen` will reopen this PR if it is closed
- `@dependabot close` will close this PR and stop Dependabot recreating
it. You can achieve the same result by closing it manually
- `@dependabot ignore this major version` will close this PR and stop
Dependabot creating any more for this major version (unless you reopen
the PR or upgrade to it yourself)
- `@dependabot ignore this minor version` will close this PR and stop
Dependabot creating any more for this minor version (unless you reopen
the PR or upgrade to it yourself)
- `@dependabot ignore this dependency` will close this PR and stop
Dependabot creating any more for this dependency (unless you reopen the
PR or upgrade to it yourself)


</details>

Signed-off-by: dependabot[bot] <[email protected]>
Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

10 participants