sporadic panics when talking to unboundid java ldap server during startup

[dirkm]

Hi,

We are using go-ldap v2.5.1 against a unboundid ldap-server (https://ldap.com/unboundid-ldap-sdk-for-java/) ,and get sporadic panics from within go-ldap, when the unbound-id server is still starting up during a connection request. the ldap.Dial returns without an error, the panic occurs during the SetTimeout

Below is the snippet from our code used to connect:

cli, err := ldap.Dial("tcp", serverAddr)
if err != nil {
  LogErrorf("2017;Error while trying to do a Ldap dial %v", err)
  return nil, err
}
// cli.Debug = true
cli.SetTimeout(clientConfig.TimeOutMs * time.Millisecond)

the panic looks like

2018-11-02T11:33:03.972822+01:00 myproject bash: 2018/11/02 11:33:03 Received unexpected message 1, false
2018-11-02T11:33:03.973052+01:00 myproject bash: LDAP Response: (Universal, Constructed, Sequence and Sequence of) Len=12 "<nil>"
2018-11-02T11:33:03.973283+01:00 myproject bash: Message ID: (Universal, Primitive, Integer) Len=1 "1"
2018-11-02T11:33:03.973480+01:00 myproject bash: Bind Response: (Application, Constructed, 0x01) Len=7 "<nil>"
2018-11-02T11:33:03.973678+01:00 myproject bash: Result Code (Success): (Universal, Primitive, Enumerated) Len=1 "0"
2018-11-02T11:33:03.973874+01:00 myproject bash: Matched DN: (Universal, Primitive, Octet String) Len=0 ""
2018-11-02T11:33:03.974077+01:00 myproject bash: Error Message: (Universal, Primitive, Octet String) Len=0 ""
2018-11-02T11:33:07.075943+01:00 myproject bash: panic: runtime error: invalid memory address or nil pointer dereference
2018-11-02T11:33:07.076090+01:00 myproject bash: [signal SIGSEGV: segmentation violation code=0x1 addr=0x70 pc=0x66be72]
2018-11-02T11:33:07.076230+01:00 myproject bash: goroutine 1 [running]:
2018-11-02T11:33:07.076334+01:00 myproject bash: vendor/gopkg.in/ldap%2ev2.(*Conn).SetTimeout(...)
2018-11-02T11:33:07.076446+01:00 myproject bash: vendor/gopkg.in/ldap.v2/conn.go:194

I have some problems finding wireshark traces, but have the feeling that we somehow get disconnected after dial succeeds. If I try to put cli.Debug on, I get a very similar panic, leading me to think that cli is somehow not in a stable state.

(the go-ldap runs fine if the unbound ldap server is fully running when trying to connect).

[johnweldon]

Can you verify that clientConfig is not nil? Or, can you reproduce the panic if you use a constant value instead of clientConfig.TimeOutMs?

[dirkm]

I will doublecheck with a const timeout.

[dirkm]

To answer your question: The clientConfig value is non-nil.

It seems that in some error-cases ldap.Dial return nil as the conn and nil as the err. I am not sure if this is expected behaviour, but checking if the conn is nil after a dial works around the issue for me.

if cli == nil {
    log.Errorf("0;client connection closed unexpectedly")
    return nil, fmt.Errorf("client connection closed unexpectedly by server")
}

[chrisfair]

I can confirm this as well. If I connect to a server and it does not return with anything (but the connection is successful and NON NIL) the code crashes. I may see if I can fix it for my app because I cannot have a crash on slow connection. A message saying that I have a failed (or too slow) connection would be better.

[chrisfair]

Here is the error that I see

panic: runtime error: invalid memory address or nil pointer dereference [signal SIGSEGV: segmentation violation code=0x1 addr=0x50 pc=0x5c4156]

goroutine 1 [running]: github.com/chrisfair/ldap.(Conn).nextMessageID(...) /home/cfair/go/src/github.com/chrisfair/ldap/conn.go:235 github.com/chrisfair/ldap.(Conn).SimpleBind(0x0, 0xc0000e7d48, 0x0, 0x0, 0x0) /home/cfair/go/src/github.com/chrisfair/ldap/bind.go:54 +0xa6 github.com/chrisfair/ldap.(*Conn).Bind(...) /home/cfair/go/src/github.com/chrisfair/ldap/bind.go:116 /home/cfair/go/src/test/ldapTools.Connect(0xc0000e7e18, 0x7fffd713aed8, 0x7) /home/cfair/go/src/test/ldapTools/conn.go:70 +0x9b /home/cfair/go/src/test/ldapTools.GetAdGroups(0x7fffd713aea2, 0x11, 0x7fffd713aebc, 0x11, 0x7fffd713aed8, 0x7, 0xc0000a0100, 0xc0000a4290, 0x7, 0x0, ...) /home/cfair/go/src/test/ldapTools/ldap.go:75 +0x34e main.main() /home/cfair/go/src/test/main.go:63 +0x34f

[marcotuna]

Hello, I am going to restore this topic This is happening with me as well

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x50 pc=0x618bb1]

goroutine 1 [running]:
github.com/go-ldap/ldap/v3.(*Conn).nextMessageID(...)
        /home/unknown/go/pkg/mod/github.com/go-ldap/ldap/v3@v3.1.8/conn.go:282
github.com/go-ldap/ldap/v3.(*Conn).doRequest(0x0, 0x6efc20, 0xc00009a040, 0xc000144480, 0x1, 0x28)
        /home/unknown/go/pkg/mod/github.com/go-ldap/ldap/v3@v3.1.8/request.go:26 +0x61
github.com/go-ldap/ldap/v3.(*Conn).SimpleBind(0x0, 0xc00009a040, 0x0, 0x0, 0x0)
        /home/unknown/go/pkg/mod/github.com/go-ldap/ldap/v3@v3.1.8/bind.go:64 +0x99
github.com/go-ldap/ldap/v3.(*Conn).Bind(...)
        /home/unknown/go/pkg/mod/github.com/go-ldap/ldap/v3@v3.1.8/bind.go:103
github.com/REDACTED/REDACTED/pkg/auth/ldap.bindUser(0x0, 0xc0000240f0, 0x43, 0xc00001a270, 0x20, 0x3, 0x0)
        /home/unknown/Documents/Projects/REDACTED/pkg/auth/ldap/ldap.go:171 +0x19d
github.com/REDACTED/REDACTED/pkg/auth/ldap.(*Source).LdapSearch(0xc000133ce0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /home/unknown/Documents/Projects/REDACTED/pkg/auth/ldap/ldap.go:359 +0x22f
main.main()
        /home/unknown/Documents/Projects/REDACTED/cmd/ldap_ovpn/main.go:45 +0x1e3
exit status 2

I believe that the server for some reason blocked my requests, because I tested the same code with exactly the same configurations in other machine (different ip address) and it didn't happened.

This error is happening since v2, I migrated to v3 to see if the error was fixed but it isn't.

The fix for this is on the comment from @dirkm. Prior to bind ldap, we must ensure that ldap.Conn is not nil.

[stefanmcshane]

Hi Marco, can you test this with v3.1.9?

Potentially related to #263