server panic during juju status if no status history for a unit

[Nate Finch]

reported by user running 2.0 beta12, but the problem exists in master, too (currently beta16).

2016-08-16 17:00:04 INFO juju.apiserver request_notifier.go:68 [A] API connection from 172.16.0.112:47996
2016-08-16 17:00:04 DEBUG juju.apiserver utils.go:61 validate model uuid: controller model - 88767b2d-305f-46c4-87d7-8484d36683e2
2016-08-16 17:00:04 DEBUG juju.apiserver request_notifier.go:113 <- [A] {"request-id":1,"type":"Admin","version":3,"request":"Login","params":"'params redacted'"}
2016-08-16 17:00:04 DEBUG juju.apiserver request_notifier.go:138 -> [A] 221.781µs {"request-id":1,"error":"login for \"machine-1\" blocked because upgrade in progress","response":"'body redacted'"} Admin[""].Login
2016-08-16 17:00:04 INFO juju.apiserver request_notifier.go:78 [A] API connection terminated after 1.158908ms
2016-08-16 17:00:04 DEBUG juju.apiserver admin.go:170 hostPorts: [[172.16.0.111:17070 127.0.0.1:17070 [::1]:17070] [172.16.0.110:17070 127.0.0.1:17070 [::1]:17070] [172.16.0.112:17070 127.0.0.1:17070 [::1]:17070] [172.16.0.113:17070 127.0.0.1:17070 [::1]:17070] [172.16.0.114:17070 127.0.0.1:17070 [::1]:17070]]
2016-08-16 17:00:04 DEBUG juju.apiserver request_notifier.go:138 -> [8] 56.416425ms {"request-id":1,"response":"'body redacted'"} Admin[""].Login
2016-08-16 17:00:04 DEBUG juju.apiserver request_notifier.go:113 <- [8] user-admin@local {"request-id":3,"type":"Client","version":1,"request":"FullStatus","params":"'params redacted'"}
2016-08-16 17:00:04 INFO juju.apiserver request_notifier.go:68 [B] API connection from 172.16.0.110:59378
2016-08-16 17:00:04 DEBUG juju.apiserver utils.go:61 validate model uuid: controller model - 88767b2d-305f-46c4-87d7-8484d36683e2
2016-08-16 17:00:04 INFO juju.apiserver request_notifier.go:78 [B] API connection terminated after 1.077788ms
2016-08-16 17:00:04 INFO juju.apiserver request_notifier.go:68 [C] API connection from 172.16.0.110:59390
2016-08-16 17:00:04 DEBUG juju.apiserver utils.go:74 validate model uuid: 926ab274-5671-4018-81b5-29ad7ee05bb9
2016-08-16 17:00:04 INFO juju.apiserver request_notifier.go:78 [C] API connection terminated after 918.604µs
2016-08-16 17:00:04 DEBUG juju.apiserver.client status.go:169 Applications: map[keystone:keystone mysql:mysql nova-compute:nova-compute openstack-dashboard:openstack-dashboard ceph-radosgw:ceph-radosgw cinder:cinder cinder-ceph:cinder-ceph glance:glance neutron-gateway:neutron-gateway neutron-openvswitch:neutron-openvswitch nova-cloud-controller:nova-cloud-controller ceph-osd:ceph-osd neutron-api:neutron-api rabbitmq-server:rabbitmq-server ceph-mon:ceph-mon ntp:ntp]
panic: runtime error: index out of range

goroutine 462 [running]:
panic(0x24793c0, 0xc82000e030)
 /usr/lib/go-1.6/src/runtime/panic.go:481 +0x3e6
github.com/juju/juju/apiserver/client.(*statusContext).processApplication(0xc82038a360, 0xc8202ee780, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
 /build/juju-core-dFYilU/juju-core-2.0-beta12/src/github.com/juju/juju/apiserver/client/status.go:613 +0xa94
github.com/juju/juju/apiserver/client.(*statusContext).processApplications(0xc82038a360, 0xc8204b1770)
 /build/juju-core-dFYilU/juju-core-2.0-beta12/src/github.com/juju/juju/apiserver/client/status.go:562 +0x116
github.com/juju/juju/apiserver/client.(*Client).FullStatus(0xc82064c290, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
 /build/juju-core-dFYilU/juju-core-2.0-beta12/src/github.com/juju/juju/apiserver/client/status.go:264 +0xf59
reflect.Value.call(0x28a42e0, 0xc82064c290, 0x2613, 0x29a89a0, 0x4, 0xc8203041c0, 0x1, 0x1, 0x0, 0x0, ...)
 /usr/lib/go-1.6/src/reflect/value.go:435 +0x120d
reflect.Value.Call(0x28a42e0, 0xc82064c290, 0x2613, 0xc8203041c0, 0x1, 0x1, 0x0, 0x0, 0x0)
 /usr/lib/go-1.6/src/reflect/value.go:303 +0xb1
github.com/juju/juju/rpc/rpcreflect.newMethod.func6(0x28a42e0, 0xc82064c290, 0x16, 0x240dda0, 0xc820107880, 0x199, 0x0, 0x0, 0x0, 0x0, ...)
 /build/juju-core-dFYilU/juju-core-2.0-beta12/src/github.com/juju/juju/rpc/rpcreflect/type.go:323 +0x14b
github.com/juju/juju/apiserver.(*srvCaller).Call(0xc8201e2280, 0x0, 0x0, 0x240dda0, 0xc820107880, 0x199, 0x0, 0x0, 0x0, 0x0, ...)
 /build/juju-core-dFYilU/juju-core-2.0-beta12/src/github.com/juju/juju/apiserver/root.go:126 +0x120
github.com/juju/juju/rpc.(*Conn).runRequest(0xc8202c30e0, 0x7f28f9b398c0, 0xc8201e2280, 0x3156a50, 0x3, 0xc82059735a, 0x6, 0x1, 0x0, 0x0, ...)
 /build/juju-core-dFYilU/juju-core-2.0-beta12/src/github.com/juju/juju/rpc/server.go:520 +0xd9
created by github.com/juju/juju/rpc.(*Conn).handleRequest
 /build/juju-core-dFYilU/juju-core-2.0-beta12/src/github.com/juju/juju/rpc/server.go:450 +0x6d0
2016-08-16 17:00:04 INFO juju.cmd supercommand.go:63 running jujud [2.0-beta12 gc go1.6.2]

pretty obvious missing length check here: https://github.com/juju/juju/blob/juju-2.0-beta12/apiserver/client/status.go#L613

[Hrvoje (hrvoje-habjanic)]

Hi.

Any estimation on when beta18 will become available via apt (ppa)?

Regards,

H.

[Anastasia (anastasia-macmood)]

@Hrvoje,

Beta18 will come out at the end of this week \o/

[Hrvoje (hrvoje-habjanic)]

\o/

Eagerly waiting for it!

H.

[Hrvoje (hrvoje-habjanic)]

Maybe fix is released, but now with beta18, everything is broken:

$ juju ssh --debug -m controller 0 sudo su -
20:50:17 INFO juju.cmd supercommand.go:63 running juju [2.0-beta18 gc go1.6]
20:50:17 DEBUG juju.cmd supercommand.go:64 args: []string{"juju", "ssh", "--debug", "-m", "controller", "0", "sudo", "su", "-"}
20:50:17 INFO juju.juju api.go:72 connecting to API addresses: [192.168.10.100:17070 192.168.200.100:17070]
20:50:17 INFO juju.api apiclient.go:507 dialing "wss://192.168.10.100:17070/model/8e0bd434-31df-42b6-8bf8-48555f6cd57f/api"
20:50:17 INFO juju.api apiclient.go:507 dialing "wss://192.168.200.100:17070/model/8e0bd434-31df-42b6-8bf8-48555f6cd57f/api"
20:50:17 INFO juju.api apiclient.go:302 connection established to "wss://192.168.10.100:17070/model/8e0bd434-31df-42b6-8bf8-48555f6cd57f/api"
20:50:17 ERROR cmd supercommand.go:458 invalid controller tag "" returned from login: "" is not a valid tag
20:50:17 DEBUG cmd supercommand.go:459 (error details: [{github.com/juju/juju/cmd/juju/commands/ssh.go:81: } {github.com/juju/juju/cmd/juju/commands/ssh_common.go:105: } {github.com/juju/juju/cmd/juju/commands/ssh_common.go:263: } {github.com/juju/juju/cmd/juju/commands/ssh_common.go:270: } {github.com/juju/juju/juju/api.go:77: } {github.com/juju/juju/api/apiclient.go:242: } {github.com/juju/juju/api/state.go:126: } {github.com/juju/juju/api/state.go:160: invalid controller tag "" returned from login} {"" is not a valid tag}])

What now?

H.

[Ian Booth (wallyworld)]

This looks like a controller running beta17 or earlier being used with a beta18 client. There are no compatibility guarantees across betas. You could try switching to the controller model and then running "juju upgrade-juju" using the beta18 client. Depending on how old your running controller is, this should fix the problem. Once the release candidate comes out, we will start being compatible across releases.

[Hrvoje (hrvoje-habjanic)]

Hi.

Yes, controller is beta15, and now client is beta18. This did work with controller beta15 and client beta17.

Almost any juju command ends up with the same error:

$ juju upgrade-juju -m controller --debug
23:19:41 INFO juju.cmd supercommand.go:63 running juju [2.0-beta18 gc go1.6]
23:19:41 DEBUG juju.cmd supercommand.go:64 args: []string{"juju", "upgrade-juju", "-m", "controller", "--debug"}
23:19:41 INFO juju.juju api.go:72 connecting to API addresses: [192.168.10.100:17070 192.168.200.100:17070]
23:19:41 INFO juju.api apiclient.go:507 dialing "wss://192.168.10.100:17070/model/8e0bd434-31df-42b6-8bf8-48555f6cd57f/api"
23:19:41 INFO juju.api apiclient.go:507 dialing "wss://192.168.200.100:17070/model/8e0bd434-31df-42b6-8bf8-48555f6cd57f/api"
23:19:41 INFO juju.api apiclient.go:302 connection established to "wss://192.168.10.100:17070/model/8e0bd434-31df-42b6-8bf8-48555f6cd57f/api"
23:19:41 ERROR cmd supercommand.go:458 invalid controller tag "" returned from login: "" is not a valid tag
23:19:41 DEBUG cmd supercommand.go:459 (error details: [{github.com/juju/juju/cmd/modelcmd/modelcommand.go:171: } {github.com/juju/juju/juju/api.go:77: } {github.com/juju/juju/api/apiclient.go:242: } {github.com/juju/juju/api/state.go:126: } {github.com/juju/juju/api/state.go:160: invalid controller tag "" returned from login} {"" is not a valid tag}])

So, i guess, redeploy is my only option?

It would be nice to put warning that beta18 is not backward compatible like previous betas ...

Regards,

H.

[Ian Booth (wallyworld)]

Given how much has changed between beta15 and beta18, then it may be that a redeploy is the only option. You could try running upgrade, first to the controller model and then to any hosted models.

Unfortunately, there has never been compatibility guarantees with any of the betas - the pace of development has been too great to be able to do that. We needed to devote the resources to getting as many features packed into 2.0 as possible before release. If it has worked, that's been by coincidence. But we will definitely guarantee compatibility going forward when the RC lands.