panics in jujud 2.3.8

Bug #1791078 reported by Junien F
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Canonical Juju
Won't Fix
Low
Unassigned

Bug Description

Hi,

We had 3 different jujud panics today. This is 2.3.8. The panics happened after a full controller restart, which made it all kinds of sad.

Thanks

2018-09-06 05:58:04 CRITICAL juju.rpc server.go:526 panic running request {MethodCaller:0xc44238c100 transformErrors:0x1362320 hdr:{RequestId:2 Request:{Type:Client Version:1 Id: Action:FullStatus} Error: ErrorCode: Version:1}} with arg {Patterns:[]}: invalid user tag ""
goroutine 285481 [running]:
runtime/debug.Stack(0xc455c0be88, 0x27be5c0, 0xc46c65a6d0)
        /snap/go/1880/src/runtime/debug/stack.go:24 +0xa7
github.com/juju/juju/rpc.(*Conn).runRequest.func1(0xc455c0df30, 0x29d1f20, 0xc44ce9b6e0, 0x199, 0xc44d76e500, 0x31edea0, 0xc44ce9b6c0)
        /workspace/src/github.com/juju/juju/rpc/server.go:527 +0xbe
panic(0x27be5c0, 0xc46c65a6d0)
        /snap/go/1880/src/runtime/panic.go:502 +0x229
gopkg.in/juju/names%2ev2.NewUserTag(0x0, 0x0, 0xc4558124e0, 0x12, 0xc455c0c030, 0x1)
        /workspace/src/gopkg.in/juju/names.v2/user.go:102 +0x198
github.com/juju/juju/state.newUserAccess(0xc44daf0b80, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/state/useraccess.go:166 +0x7e
github.com/juju/juju/state.NewControllerUserAccess(0xc42107dc80, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/state/useraccess.go:140 +0x236
github.com/juju/juju/state.(*State).UserAccess(0xc42107dc80, 0xc479507265, 0xf, 0x0, 0x0, 0x3200de0, 0xc424f25ac0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/state/useraccess.go:198 +0x3fa
github.com/juju/juju/state.(*State).UserPermission(0xc42107dc80, 0xc479507265, 0xf, 0x0, 0x0, 0x3200de0, 0xc424f25ac0, 0xc455c0cb20, 0x1, 0x1, ...)
        /workspace/src/github.com/juju/juju/state/useraccess.go:147 +0x108
github.com/juju/juju/state.(*State).UserPermission-fm(0xc479507265, 0xf, 0x0, 0x0, 0x3200de0, 0xc424f25ac0, 0x26a3e80, 0xc43d25efa0, 0x0, 0x0)
        /workspace/src/github.com/juju/juju/apiserver/introspection.go:46 +0x73
github.com/juju/juju/apiserver/common.GetPermission(0xc455c0cd20, 0xc479507265, 0xf, 0x0, 0x0, 0x3200de0, 0xc424f25ac0, 0x0, 0x0, 0xc455c0ccf0, ...)
        /workspace/src/github.com/juju/juju/apiserver/common/permissions.go:67 +0x89
github.com/juju/juju/apiserver/common.HasPermission(0xc455c0cd20, 0x32010e0, 0xc461984a00, 0x2edce4a, 0x9, 0x3200de0, 0xc424f25ac0, 0xc424f25ac0, 0xc455c0cda8, 0xc424f25ac0)
        /workspace/src/github.com/juju/juju/apiserver/common/permissions.go:47 +0x122
github.com/juju/juju/apiserver.(*apiHandler).HasPermission(0xc479ae8d80, 0x2edce4a, 0x9, 0x3200de0, 0xc424f25ac0, 0x0, 0x0, 0x0)
        /workspace/src/github.com/juju/juju/apiserver/root.go:500 +0xad
github.com/juju/juju/apiserver/facades/client/client.(*Client).checkIsAdmin(0xc43c7bd710, 0xc43f387d40, 0xc4564c8420)
        /workspace/src/github.com/juju/juju/apiserver/facades/client/client/client.go:104 +0xcd
github.com/juju/juju/apiserver/facades/client/client.(*Client).FullStatus(0xc43c7bd710, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/apiserver/facades/client/client/status.go:189 +0x279
reflect.Value.call(0x2e10b20, 0xc43c7bd710, 0x2a13, 0x2ed3dbf, 0x4, 0xc44cdeb240, 0x1, 0x1, 0x9550c1, 0x27e5a60, ...)
        /snap/go/1880/src/reflect/value.go:447 +0x969
reflect.Value.Call(0x2e10b20, 0xc43c7bd710, 0x2a13, 0xc44cdeb240, 0x1, 0x1, 0x2a13, 0x6, 0x1)
        /snap/go/1880/src/reflect/value.go:308 +0xa4
github.com/juju/juju/rpc/rpcreflect.newMethod.func6(0x2e10b20, 0xc43c7bd710, 0x16, 0x29d1f20, 0xc44ce9b6e0, 0x199, 0x0, 0xc400000008, 0xc4561a5e80, 0x38, ...)
        /workspace/src/github.com/juju/juju/rpc/rpcreflect/type.go:323 +0xd1
github.com/juju/juju/apiserver.(*srvCaller).Call(0xc44238c100, 0x0, 0x0, 0x29d1f20, 0xc44ce9b6e0, 0x199, 0xc44d76e500, 0x31edea0, 0xc44ce9b6c0, 0x95b46f, ...)
        /workspace/src/github.com/juju/juju/apiserver/root.go:156 +0xd4
github.com/juju/juju/rpc.(*Conn).runRequest(0xc44d76e500, 0x31f98a0, 0xc44238c100, 0x2fdda20, 0x2, 0xc4382ab9d2, 0x6, 0x1, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/rpc/server.go:533 +0x13b
created by github.com/juju/juju/rpc.(*Conn).handleRequest
        /workspace/src/github.com/juju/juju/rpc/server.go:452 +0x8fb

2018-09-06 07:27:30 CRITICAL juju.rpc server.go:526 panic running request {MethodCaller:{paramsType:<nil> resultType:<nil> rootValue:{typ:0x2cbd5a0 ptr:0xc44084f590 flag:22} rootMethod:{Call:0x954e40 ObjType:0xc4296a8870} objMethod:{Params:0x2c61c00 Result:0x2d42320 Call:0x955530}} transformErrors:0x1362320 hdr:{RequestId:1 Request:{Type:Admin Version:3 Id: Action:Login} Error: ErrorCode: Version:1}} with arg {AuthTag:<REDACTED> Credentials:<REDACTED> Nonce: Macaroons:[] CLIArgs:juju status --format yaml --output /path/to/foo UserData:}: invalid user tag ""
goroutine 23075 [running]:
runtime/debug.Stack(0xc437ff9dc0, 0x27be5c0, 0xc455b5fd50)
        /snap/go/1880/src/runtime/debug/stack.go:24 +0xa7
github.com/juju/juju/rpc.(*Conn).runRequest.func1(0xc437ffbf30, 0x2c61c00, 0xc447317180, 0x199, 0xc4253e0800, 0x31edea0, 0xc44695c5e0)
        /workspace/src/github.com/juju/juju/rpc/server.go:527 +0xbe
panic(0x27be5c0, 0xc455b5fd50)
        /snap/go/1880/src/runtime/panic.go:502 +0x229
gopkg.in/juju/names%2ev2.NewUserTag(0x0, 0x0, 0xc4477e2b60, 0x12, 0xc437ff9f68, 0x1)
        /workspace/src/gopkg.in/juju/names.v2/user.go:102 +0x198
github.com/juju/juju/state.newUserAccess(0xc4418d9100, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/state/useraccess.go:166 +0x7e
github.com/juju/juju/state.NewControllerUserAccess(0xc420345e00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/state/useraccess.go:140 +0x236
github.com/juju/juju/state.(*State).UserAccess(0xc420345e00, 0xc4448fba85, 0x19, 0x0, 0x0, 0x3200de0, 0xc4470b1530, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/state/useraccess.go:198 +0x3fa
github.com/juju/juju/state.ControllerAccess(0xc420345e00, 0x32010e0, 0xc446983ac0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/state/state.go:181 +0x156
github.com/juju/juju/apiserver.(*admin).checkUserPermissions(0xc44084f590, 0xc4448fba85, 0x19, 0x0, 0x0, 0xc4498e6c00, 0x3205420, 0xc42067d2a0, 0x1)
        /workspace/src/github.com/juju/juju/apiserver/admin.go:373 +0x13f
github.com/juju/juju/apiserver.(*admin).fillLoginDetails(0xc44084f590, 0xc44695c6a0, 0xc44695d380, 0x31e1160, 0xc446413ad0)
        /workspace/src/github.com/juju/juju/apiserver/admin.go:331 +0x2de
github.com/juju/juju/apiserver.(*admin).authenticate(0xc44084f590, 0xc4448fba80, 0x1e, 0xc4448fbaa0, 0x20, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/apiserver/admin.go:283 +0x266
github.com/juju/juju/apiserver.(*admin).login(0xc44084f590, 0xc4448fba80, 0x1e, 0xc4448fbaa0, 0x20, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/apiserver/admin.go:90 +0x119
github.com/juju/juju/apiserver.(*admin).Login(0xc44084f590, 0xc4448fba80, 0x1e, 0xc4448fbaa0, 0x20, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/apiserver/admin.go:66 +0xba
reflect.Value.call(0x2cbd5a0, 0xc44084f5d8, 0x693, 0x2ed3dbf, 0x4, 0xc44695c680, 0x1, 0x1, 0x9550c1, 0x27e5a60, ...)
        /snap/go/1880/src/reflect/value.go:447 +0x969
reflect.Value.Call(0x2cbd5a0, 0xc44084f5d8, 0x693, 0xc44695c680, 0x1, 0x1, 0x693, 0x2cbd5a0, 0xc44084f590)
        /snap/go/1880/src/reflect/value.go:308 +0xa4
github.com/juju/juju/rpc/rpcreflect.newMethod.func6(0x2cbd5a0, 0xc44084f5d8, 0x96, 0x2c61c00, 0xc447317180, 0x199, 0xc44084f5d8, 0x96, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/rpc/rpcreflect/type.go:323 +0xd1
github.com/juju/juju/rpc/rpcreflect.methodCaller.Call(0x0, 0x0, 0x0, 0x0, 0x2cbd5a0, 0xc44084f590, 0x16, 0xc42975a660, 0xc4296a8870, 0x324ae20, ...)
        /workspace/src/github.com/juju/juju/rpc/rpcreflect/value.go:125 +0xff
github.com/juju/juju/rpc.(*Conn).runRequest(0xc4253e0800, 0x3200020, 0xc447317110, 0x2fdda20, 0x1, 0xc446278099, 0x5, 0x3, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/rpc/server.go:533 +0x13b
created by github.com/juju/juju/rpc.(*Conn).handleRequest
        /workspace/src/github.com/juju/juju/rpc/server.go:452 +0x8fb

2018-09-06 07:18:11 CRITICAL juju.rpc server.go:526 panic running request {MethodCaller:0xc48fa309c0 transformErrors:0x1362320 hdr:{RequestId:131 Request:{Type:MetricsAdder Version:2 Id: Action:AddMetricBatches} Error: ErrorCode: Version:1}} with arg {Batches:[{Tag:unit-<REDACTED> Batch:{UUID:<REDACTED> CharmURL:cs:<REDACTED> Created:2018-09-06 07:13:24.310719202 +0000 UTC Metrics:[{Key:juju-units Value:1 Time:2018-09-06 07:13:24.311071045 +0000 UTC}]}}]}: runtime error: invalid memory address or nil pointer dereference
goroutine 3089558 [running]:
runtime/debug.Stack(0xc4a41fd450, 0x2923ae0, 0x4962110)
        /snap/go/1880/src/runtime/debug/stack.go:24 +0xa7
github.com/juju/juju/rpc.(*Conn).runRequest.func1(0xc4a41fdf30, 0x29cf0a0, 0xc4801914a0, 0x199, 0xc4ac7bf480, 0x31edea0, 0xc480191480)
        /workspace/src/github.com/juju/juju/rpc/server.go:527 +0xbe
panic(0x2923ae0, 0x4962110)
        /snap/go/1880/src/runtime/panic.go:502 +0x229
github.com/juju/juju/state.(*Application).MetricCredentials(...)
        /workspace/src/github.com/juju/juju/state/application.go:1856
github.com/juju/juju/state.(*State).AddMetrics(0xc4369e4a80, 0xc4962aa5a0, 0x24, 0xc4b5128ac0, 0x17, 0x128532e2, 0xed322ca94, 0x0, 0xc458030580, 0x1, ...)
        /workspace/src/github.com/juju/juju/state/metrics.go:135 +0x1db
github.com/juju/juju/apiserver/facades/agent/metricsadder.(*MetricsAdderAPI).AddMetricBatches(0xc4afe3a268, 0xc4c3f48300, 0x1, 0x4, 0x0, 0x0, 0x0, 0x0, 0x0)
        /workspace/src/github.com/juju/juju/apiserver/facades/agent/metricsadder/metricsadder.go:64 +0x4e6
reflect.Value.call(0x28a2b20, 0xc4afe3a268, 0x213, 0x2ed3dbf, 0x4, 0xc4b68479a0, 0x1, 0x1, 0x95512c, 0x27e5a60, ...)
        /snap/go/1880/src/reflect/value.go:447 +0x969
reflect.Value.Call(0x28a2b20, 0xc4afe3a268, 0x213, 0xc4b68479a0, 0x1, 0x1, 0x213, 0x18, 0xc4b35c35c8)
        /snap/go/1880/src/reflect/value.go:308 +0xa4
github.com/juju/juju/rpc/rpcreflect.newMethod.func6(0x28a2b20, 0xc4afe3a268, 0x16, 0x29cf0a0, 0xc4801914a0, 0x199, 0x0, 0xc400000008, 0xc47c52f640, 0x38, ...)
        /workspace/src/github.com/juju/juju/rpc/rpcreflect/type.go:323 +0xd1
github.com/juju/juju/apiserver.(*srvCaller).Call(0xc48fa309c0, 0x0, 0x0, 0x29cf0a0, 0xc4801914a0, 0x199, 0xc4ac7bf480, 0x31edea0, 0xc480191480, 0x95b46f, ...)
        /workspace/src/github.com/juju/juju/apiserver/root.go:156 +0xd4
github.com/juju/juju/rpc.(*Conn).runRequest(0xc4ac7bf480, 0x31f98a0, 0xc48fa309c0, 0x2fdda20, 0x83, 0xc483de4640, 0xc, 0x2, 0x0, 0x0, ...)
        /workspace/src/github.com/juju/juju/rpc/server.go:533 +0x13b
created by github.com/juju/juju/rpc.(*Conn).handleRequest
        /workspace/src/github.com/juju/juju/rpc/server.go:452 +0x8fb

Revision history for this message
Tim Penhey (thumper) wrote :

I'm wondering how much of this is fallout from the API servers panicing due to the bug around determining collection sizes for the db log pruning.

Did the machines recover from the panics? Are they running again?

Perhaps we need to write some form of intergrity check for the database to see if expectations aren't being met due to previous transactions aborted mid flow due to earlier panics.

Changed in juju:
status: New → Triaged
importance: Undecided → High
milestone: none → 2.3.9
Revision history for this message
Tim Penhey (thumper) wrote :

At a minimum we need to evaluate why these panics occurred.

Revision history for this message
Junien F (axino) wrote :

> Did the machines recover from the panics? Are they running again?

Yes, and yes. The panics caused jujud-machine-X to crash, and then systemd restarted it.

Ian Booth (wallyworld)
Changed in juju:
milestone: 2.3.9 → 2.3.10
Revision history for this message
John A Meinel (jameinel) wrote : Re: [Bug 1791078] [NEW] panics in jujud 2.3.8
Download full text (12.0 KiB)

Looking at the stack trace it is code that is calling NewUserTag without
validating it has a valid username in there. and, in fact, it appears to
have an empty string instead of a username.

Looks like code that is missing IsValidUsername. (though having the New*Tag
functions panic when given bad data is a bit of a trap.)

John
=:->

On Thu, Sep 6, 2018, 16:30 Junien Fridrick <email address hidden>
wrote:

> Public bug reported:
>
> Hi,
>
> We had 3 different jujud panics today. This is 2.3.8. The panics
> happened after a full controller restart, which made it all kinds of
> sad.
>
> Thanks
>
>
> 2018-09-06 05:58:04 CRITICAL juju.rpc server.go:526 panic running request
> {MethodCaller:0xc44238c100 transformErrors:0x1362320 hdr:{RequestId:2
> Request:{Type:Client Version:1 Id: Action:FullStatus} Error: ErrorCode:
> Version:1}} with arg {Patterns:[]}: invalid user tag ""
> goroutine 285481 [running]:
> runtime/debug.Stack(0xc455c0be88, 0x27be5c0, 0xc46c65a6d0)
> /snap/go/1880/src/runtime/debug/stack.go:24 +0xa7
> github.com/juju/juju/rpc.(*Conn).runRequest.func1(0xc455c0df30,
> 0x29d1f20, 0xc44ce9b6e0, 0x199, 0xc44d76e500, 0x31edea0, 0xc44ce9b6c0)
> /workspace/src/github.com/juju/juju/rpc/server.go:527 +0xbe
> panic(0x27be5c0, 0xc46c65a6d0)
> /snap/go/1880/src/runtime/panic.go:502 +0x229
> gopkg.in/juju/names%2ev2.NewUserTag(0x0, 0x0, 0xc4558124e0, 0x12,
> 0xc455c0c030, 0x1)
> /workspace/src/gopkg.in/juju/names.v2/user.go:102 +0x198
> github.com/juju/juju/state.newUserAccess(0xc44daf0b80, 0x0, 0x0, 0x0,
> 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
> /workspace/src/github.com/juju/juju/state/useraccess.go:166 +0x7e
> github.com/juju/juju/state.NewControllerUserAccess(0xc42107dc80, 0x0,
> 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
> /workspace/src/github.com/juju/juju/state/useraccess.go:140 +0x236
> github.com/juju/juju/state.(*State).UserAccess(0xc42107dc80,
> 0xc479507265, 0xf, 0x0, 0x0, 0x3200de0, 0xc424f25ac0, 0x0, 0x0, 0x0, ...)
> /workspace/src/github.com/juju/juju/state/useraccess.go:198 +0x3fa
> github.com/juju/juju/state.(*State).UserPermission(0xc42107dc80,
> 0xc479507265, 0xf, 0x0, 0x0, 0x3200de0, 0xc424f25ac0, 0xc455c0cb20, 0x1,
> 0x1, ...)
> /workspace/src/github.com/juju/juju/state/useraccess.go:147 +0x108
> github.com/juju/juju/state.(*State).UserPermission-fm(0xc479507265, 0xf,
> 0x0, 0x0, 0x3200de0, 0xc424f25ac0, 0x26a3e80, 0xc43d25efa0, 0x0, 0x0)
> /workspace/src/github.com/juju/juju/apiserver/introspection.go:46
> +0x73
> github.com/juju/juju/apiserver/common.GetPermission(0xc455c0cd20,
> 0xc479507265, 0xf, 0x0, 0x0, 0x3200de0, 0xc424f25ac0, 0x0, 0x0,
> 0xc455c0ccf0, ...)
> /workspace/src/
> github.com/juju/juju/apiserver/common/permissions.go:67 +0x89
> github.com/juju/juju/apiserver/common.HasPermission(0xc455c0cd20,
> 0x32010e0, 0xc461984a00, 0x2edce4a, 0x9, 0x3200de0, 0xc424f25ac0,
> 0xc424f25ac0, 0xc455c0cda8, 0xc424f25ac0)
> /workspace/src/
> github.com/juju/juju/apiserver/common/permissions.go:47 +0x122
> github.com/juju/juju/apiserver.(*apiHandler).HasPermission(0xc479ae8d80,
> 0x2edce4a, 0x9, 0x3200de0, 0xc424f25ac0, 0x0, 0x0, 0x0...

Revision history for this message
Anastasia (anastasia-macmood) wrote :

Removing from a milestone as this work will not be done in 2.3 series.

Changed in juju:
milestone: 2.3.10 → none
Revision history for this message
Joseph Phillips (manadart) wrote :

Marking as "won't fix" given the age of this bug. To my knowledge we have not observed it on more recent versions.

Changed in juju:
importance: High → Low
status: Triaged → Won't Fix
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.