(1.20.11, 1.21) juju status panics when no .jenv is present

[Chris Stratford]

We have just tried updating from juju-core 1.18.4 to 1.20.11 (precise host, locally built binaries, from the sources on ppa.launchpad.net/juju/stable/ubuntu)

For some of our environments it works fine. For others we get a panic, as below.

To eliminate our build, I've also tried a locally installed juju-core 1.21 (using the binaries from the ppa this time) against one of the failing environments with the same result.

$ juju status
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x28 pc=0x48ec97]

goroutine 1 [running]:
runtime.panic(0xcf17c0, 0x1a55988)
 /usr/lib/go/src/pkg/runtime/panic.c:266 +0xb6
github.com/juju/juju/juju.cacheChangedAPIInfo(0x0, 0x0, 0x7f7f7373e598, 0xc210146c80, 0xc210146c80, ...)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/juju/api.go:394 +0x1d7
github.com/juju/juju/juju.newAPIFromStore(0x7ffff0ae6c16, 0x12, 0x7f7f7373b538, 0xc2101f34f0, 0x10054a0, ...)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/juju/api.go:235 +0x659
github.com/juju/juju/juju.newAPIClient(0x7ffff0ae6c16, 0x12, 0xffffffffffffffff, 0x503d47, 0x1a4eef0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/juju/api.go:127 +0x7b
github.com/juju/juju/juju.NewAPIClientFromName(0x7ffff0ae6c16, 0x12, 0xe1b400, 0x0, 0x0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/juju/api.go:86 +0x31
main.func·008(0x7ffff0ae6c16, 0x12, 0x0, 0x0, 0x0, ...)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/cmd/juju/status.go:77 +0x31
main.(*StatusCommand).Run(0xc2101e2280, 0xc2100df3c0, 0x0, 0x0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/cmd/juju/status.go:86 +0xbf
github.com/juju/juju/cmd/envcmd.(*environCommandWrapper).Run(0xc2101e1ba0, 0xc2100df3c0, 0xb529a0, 0xc2101f34e0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/cmd/envcmd/environmentcommand.go:1 +0x3d
main.(*envCmdWrapper).Run(0xc2101e1bc0, 0xc2100df3c0, 0x0, 0x0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/cmd/juju/addmachine.go:1 +0x3d
github.com/juju/cmd.(*SuperCommand).Run(0xc2101c1d10, 0xc2100df3c0, 0xc2100df3c0, 0x0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/cmd/supercommand.go:321 +0x3ca
github.com/juju/cmd.Main(0x7f7f7373b340, 0xc2101c1d10, 0xc2100df3c0, 0xc21000a010, 0x1, ...)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/cmd/cmd.go:247 +0x283
main.Main(0xc21000a000, 0x2, 0x2)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/cmd/juju/main.go:77 +0xada
main.main()
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/cmd/juju/main.go:174 +0x44

goroutine 3 [syscall]:
os/signal.loop()
 /usr/lib/go/src/pkg/os/signal/signal_unix.go:21 +0x1e
created by os/signal.init·1
 /usr/lib/go/src/pkg/os/signal/signal_unix.go:27 +0x31

goroutine 23 [IO wait]:
net.runtime_pollWait(0x7f7f7373d788, 0x72, 0x0)
 /usr/lib/go/src/pkg/runtime/netpoll.goc:116 +0x6a
net.(*pollDesc).Wait(0xc21007f060, 0x72, 0x7f7f73734298, 0xb)
 /usr/lib/go/src/pkg/net/fd_poll_runtime.go:81 +0x34
net.(*pollDesc).WaitRead(0xc21007f060, 0xb, 0x7f7f73734298)
 /usr/lib/go/src/pkg/net/fd_poll_runtime.go:86 +0x30
net.(*netFD).Read(0xc21007f000, 0xc2100eac00, 0x400, 0x400, 0x0, ...)
 /usr/lib/go/src/pkg/net/fd_unix.go:204 +0x2a0
net.(*conn).Read(0xc2101f1bf8, 0xc2100eac00, 0x400, 0x400, 0x101c1e70, ...)
 /usr/lib/go/src/pkg/net/net.go:122 +0xc5
crypto/tls.(*block).readFromUntil(0xc2100dca20, 0x7f7f7373d858, 0xc2101f1bf8, 0x5, 0xc2101f1bf8, ...)
 /usr/lib/go/src/pkg/crypto/tls/conn.go:459 +0xb6
crypto/tls.(*Conn).readRecord(0xc210088a00, 0x17, 0x0, 0x0)
 /usr/lib/go/src/pkg/crypto/tls/conn.go:539 +0x107
crypto/tls.(*Conn).Read(0xc210088a00, 0xc2101e7000, 0x1000, 0x1000, 0x0, ...)
 /usr/lib/go/src/pkg/crypto/tls/conn.go:897 +0x135
bufio.(*Reader).fill(0xc2101f4840)
 /usr/lib/go/src/pkg/bufio/bufio.go:91 +0x110
bufio.(*Reader).ReadByte(0xc2101f4840, 0xc210161f00, 0x0, 0x0)
 /usr/lib/go/src/pkg/bufio/bufio.go:183 +0x7f
code.google.com/p/go.net/websocket.hybiFrameReaderFactory.NewFrameReader(0xc2101f4840, 0x7f7f7373e4b0, 0xc210161f00, 0x0, 0x0)
 /build/buildd-dak/juju-core-1.20.11/src/code.google.com/p/go.net/websocket/hybi.go:126 +0xc6
code.google.com/p/go.net/websocket.Codec.Receive(0xfe2450, 0xfe2458, 0xc21005c3f0, 0xb05fa0, 0xc2101c1e70, ...)
 /build/buildd-dak/juju-core-1.20.11/src/code.google.com/p/go.net/websocket/websocket.go:314 +0x168
github.com/juju/juju/rpc/jsoncodec.wsJSONConn.Receive(0xc21005c3f0, 0xb05fa0, 0xc2101c1e70, 0x0, 0x7f7f735ac958)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/rpc/jsoncodec/conn.go:25 +0x55
github.com/juju/juju/rpc/jsoncodec.(*Codec).ReadHeader(0xc2101c1e70, 0xc2101f49c0, 0x0, 0x0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/rpc/jsoncodec/codec.go:115 +0x5e4
github.com/juju/juju/rpc.(*Conn).loop(0xc210146be0, 0x1012f010, 0xc2101e3240)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/rpc/server.go:389 +0x8a
github.com/juju/juju/rpc.(*Conn).input(0xc210146be0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/rpc/server.go:362 +0x32
created by github.com/juju/juju/rpc.(*Conn).Start
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/rpc/server.go:209 +0xaa

goroutine 11 [syscall]:
runtime.goexit()
 /usr/lib/go/src/pkg/runtime/proc.c:1394

goroutine 24 [chan receive]:
github.com/juju/juju/rpc.(*Conn).Call(0xc210146be0, 0xe25550, 0x6, 0x0, 0xe1b470, ...)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/rpc/client.go:148 +0xb5
github.com/juju/juju/state/api.(*State).Call(0xc210146c80, 0xe25550, 0x6, 0xe1b470, 0x0, ...)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/state/api/apiclient.go:283 +0x105
github.com/juju/juju/state/api.(*State).Ping(0xc210146c80, 0x7f7f7373e248, 0xc21005c3f0)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/state/api/apiclient.go:269 +0x81
github.com/juju/juju/state/api.(*State).heartbeatMonitor(0xc210146c80, 0xdf8475800)
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/state/api/apiclient.go:260 +0x27
created by github.com/juju/juju/state/api.Open
 /build/buildd-dak/juju-core-1.20.11/src/github.com/juju/juju/state/api/apiclient.go:196 +0xa15

[Curtis Hovey (sinzui)]

Can you try this command to provide more information about what is happening?
    juju --debug status

[Chris Stratford (chris-gondolin)]

$ juju --debug status
2015-03-26 09:16:06 INFO juju.cmd supercommand.go:37 running juju [1.20.11-precise-amd64 gc]
2015-03-26 09:16:06 DEBUG juju.conn api.go:195 no cached API connection settings found
2015-03-26 09:16:06 INFO juju.provider.openstack provider.go:204 opening environment "prod-cdo-ciaas"
2015-03-26 09:16:06 DEBUG juju.provider.common state.go:83 waiting for addresses of state server instances [d8e0f90b-3b1f-4958-acd6-0cd74e45b99c]
2015-03-26 09:16:06 INFO juju.provider.openstack provider.go:403 instance d8e0f90b-3b1f-4958-acd6-0cd74e45b99c has floating IP address:
2015-03-26 09:16:06 INFO juju.state.api apiclient.go:242 dialing "wss://10.33.17.20:17070/"
2015-03-26 09:16:06 INFO juju.state.api apiclient.go:176 connection established to "wss://10.33.17.20:17070/"
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x28 pc=0x48ec97]

Here's nova show's output on that instance:
$ nova show d8e0f90b-3b1f-4958-acd6-0cd74e45b99c
+------------------------+-----------------------------------------------------------------------------------+
| Property | Value |
+------------------------+-----------------------------------------------------------------------------------+
| OS-DCF:diskConfig | MANUAL |
| OS-EXT-STS:power_state | 1 |
| OS-EXT-STS:task_state | - |
| OS-EXT-STS:vm_state | active |
| accessIPv4 | |
| accessIPv6 | |
| config_drive | |
| created | 2013-10-31T16:10:31Z |
| flavor | cpu2-ram1-disk20-ephemeral20 (1101) |
| hostId | 81040ec15eceb6b245ab233fca675441d9dd7f6105cea5906129b021 |
| id | d8e0f90b-3b1f-4958-acd6-0cd74e45b99c |
| image | ubuntu-precise-12.04-amd64-server-20131010 (b62349d7-0765-4866-9203-6a8c4b18d449) |
| key_name | - |
| metadata | {} |
| name | juju-prod-cdo-ciaas-machine-0 |
| nova network | 10.33.17.20 |
| progress | 0 ...

[Aaron Bentley (abentley)]

Current stable is 1.22.0. 1.20 is not getting bugfixes.

[Aaron Bentley (abentley)]

So far, this bug has not been reported in 1.23 or trunk, but we believe trunk may be affected. Status reports for trunk or 1.23 would be helpful.

[Chris Stratford (chris-gondolin)]

Using 1.23-beta1 from http://ppa.launchpad.net/juju/devel/ubuntu/pool/main/j/juju-core/ I get this:

$ juju --debug status
2015-03-26 15:40:05 INFO juju.cmd supercommand.go:37 running juju [1.23-beta1-precise-amd64 gc]
2015-03-26 15:40:05 DEBUG juju.api api.go:176 no cached API connection settings found
2015-03-26 15:40:05 INFO juju.provider.openstack provider.go:241 opening environment "prod-cdo-ciaas"
2015-03-26 15:40:05 DEBUG juju.environs utils.go:94 StateServerInstances returned: [d8e0f90b-3b1f-4958-acd6-0cd74e45b99c]
2015-03-26 15:40:05 ERROR juju.cmd supercommand.go:430 Unable to connect to environment "prod-cdo-ciaas".
Please check your credentials or use 'juju bootstrap' to create a new environment.

Error details:
config has no UUID

So, no panic now, but it still doesn't work (which I guess is progress).

One thing I have noticed: All the environments that fail are missing a ~/.juju-core/environments/thing.jenv file (not sure why, but some environments are there, some aren't)

[Martin Packman (gz)]

Looking at the 1.20 source, this seems it can happen if the jenv file for the environment is missing on disk.

environs/configstore/disk.go l118-123

func (d *diskStore) ReadInfo(envName string) (EnvironInfo, error) {
        path := d.envPath(envName)
        data, err := ioutil.ReadFile(path)
        if err != nil {
                if os.IsNotExist(err) {
                        return nil, errors.NotFoundf("environment %q", envName)

juju/api.go l181-183

        info, err := store.ReadInfo(envName)
        if err != nil && !errors.IsNotFound(err) {
                return nil, err

juju/api.go l234-235

        // Update API addresses if they've changed. Error is non-fatal.
        if localerr := cacheChangedAPIInfo(info, st); localerr != nil {

juju/api.go l383-394

func cacheChangedAPIInfo(info configstore.EnvironInfo, st apiState) error {
        ...
        endpoint := info.APIEndpoint()

Boom, nil deref.

[Aaron Bentley (abentley)]

I've filed https://bugs.launchpad.net/juju-core/+bug/1436925 to track the UUID issue

[Aaron Bentley (abentley)]

Marked invalid for trunk because comment #5 shows that trunk doesn't panic, it exhibits bug #1436925

[Jesse Meek (waigani)]

I have a PR which fixes bug #1436925 for Master: https://github.com/juju/juju/pull/1963

Two issues have been conflated here:

1) .jenv files missing env and server UUIDs
I've tested 1.23beta1 (the same that IS used) and the problem does not occur. This is because commit eae25e3a fixed this for LoginV1. The bug was reintroduced in Master by LoginV2 - my PR above fixes this.

2) Missing .jenv files
.jenv files were a requirement for 1.18 (see test above) and are still so today. If IS cannot access their environments because of missing .jenv files, I suggest they follow this tutorial to rebuild the .jenv:

http://www.metaklass.org/how-to-recover-juju-from-a-lost-juju-openstack-provider/

[Jesse Meek (waigani)]

Just tested 1.18 with creds in environments.yaml and missing .jenv. I was able to connect. 1.23-beta3 was not able to connect using the same environments.yaml. So it looks like there is actually a regression in 1.23

If this is the issue IS are hitting, as a work around in the interim, they could copy admin-secret, ca-cert etc from environments.yaml into ~/.juju/envrionment/<envname>.jenv