search

canonical / charmed-postgresql-snap

Charmed solution for PostgreSQL
Apache License 2.0
1 stars 6 forks source link

`error: cannot parse line: cannot parse token "KCMP_FILE" (line "kcmp - - KCMP_FILE")` with snapd 2.60.3 #21

Closed nobuto-m closed 1 year ago

nobuto-m commented 1 year ago

(credit for the analysis below should go to @odufourc)

Steps to reproduce

  1. juju deploy postgresql --channel 14/stable

Expected behavior

Installation completes without any error.

Actual behavior

$ juju status
Model      Controller          Cloud/Region        Version  SLA          Timestamp
psql-test  aws-ap-northeast-1  aws/ap-northeast-1  3.1.5    unsupported  21:32:44+09:00

App         Version  Status   Scale  Charm       Channel    Rev  Exposed  Message
postgresql           blocked      1  postgresql  14/stable  288  no       failed to patch snap seccomp profile

Unit           Workload  Agent  Machine  Public address  Ports  Message
postgresql/0*  blocked   idle   0        43.207.211.134         failed to patch snap seccomp profile

Machine  State    Address         Inst id              Base          AZ               Message
0        started  43.207.211.134  i-0308269f076c5ac41  ubuntu@22.04  ap-northeast-1a  running

[/var/log/juju/unit-postgresql-0.log]

2023-09-14 12:24:02 INFO juju unit_agent.go:289 Starting unit workers for "postgresql/0"
2023-09-14 12:24:02 INFO juju.worker.apicaller connect.go:163 [cf5361] "unit-postgresql-0" successfully connected to "172.31.42.12:17070"
2023-09-14 12:24:02 INFO juju.worker.apicaller connect.go:260 [cf5361] password changed for "unit-postgresql-0"
2023-09-14 12:24:02 INFO juju.worker.apicaller connect.go:163 [cf5361] "unit-postgresql-0" successfully connected to "172.31.42.12:17070"
2023-09-14 12:24:02 INFO juju.worker.upgrader upgrader.go:141 no waiter, upgrader is done
2023-09-14 12:24:02 INFO juju.worker.migrationminion worker.go:142 migration phase is now: NONE
2023-09-14 12:24:02 INFO juju.worker.logger logger.go:120 logger worker started
2023-09-14 12:24:02 ERROR juju.worker.meterstatus runner.go:93 error running "meter-status-changed": charm missing from disk
2023-09-14 12:24:02 INFO juju.worker.uniter uniter.go:354 unit "postgresql/0" started
2023-09-14 12:24:02 INFO juju.worker.uniter uniter.go:680 resuming charm install
2023-09-14 12:24:02 INFO juju.worker.uniter.charm bundles.go:81 downloading ch:amd64/jammy/postgresql-288 from API server
2023-09-14 12:24:15 INFO juju.worker.uniter uniter.go:380 hooks are retried true
2023-09-14 12:24:17 INFO juju.worker.uniter.operation runhook.go:186 ran "pgdata-storage-attached" hook (via hook dispatching script: dispatch)
2023-09-14 12:24:17 INFO juju.worker.uniter.storage resolver.go:126 initial storage attachments ready
2023-09-14 12:24:17 INFO unit.postgresql/0.juju-log server.go:325 Running legacy hooks/install.
2023-09-14 12:25:51 WARNING unit.postgresql/0.install logger.go:60 error: cannot parse line: cannot parse token "KCMP_FILE" (line "kcmp - - KCMP_FILE")
2023-09-14 12:25:51 ERROR unit.postgresql/0.juju-log server.go:325 Command '['/usr/lib/snapd/snap-seccomp', 'compile', '/var/lib/snapd/seccomp/bpf/snap.charmed-postgresql.patroni.src', '/var/lib/snapd/seccomp/bpf/snap.charmed-postgresql.patroni.bin']' returned non-zero exit status 1.
Traceback (most recent call last):
  File "/var/lib/juju/agents/unit-postgresql-0/charm/./src/charm.py", line 573, in _on_install
    self._patch_snap_seccomp_profile()
  File "/var/lib/juju/agents/unit-postgresql-0/charm/./src/charm.py", line 915, in _patch_snap_seccomp_profile
    subprocess.check_output(
  File "/usr/lib/python3.10/subprocess.py", line 421, in check_output
    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
  File "/usr/lib/python3.10/subprocess.py", line 526, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['/usr/lib/snapd/snap-seccomp', 'compile', '/var/lib/snapd/seccomp/bpf/snap.charmed-postgresql.patroni.src', '/var/lib/snapd/seccomp/bpf/snap.charmed-postgresql.patroni.bin']' returned non-zero exit status 1.
2023-09-14 12:25:51 INFO juju.worker.uniter.operation runhook.go:186 ran "install" hook (via hook dispatching script: dispatch)
2023-09-14 12:25:52 INFO juju.worker.uniter.operation runhook.go:186 ran "database-peers-relation-created" hook (via hook dispatching script: dispatch)
2023-09-14 12:25:52 INFO juju.worker.uniter.operation runhook.go:186 ran "restart-relation-created" hook (via hook dispatching script: dispatch)
2023-09-14 12:25:53 INFO juju.worker.uniter resolver.go:165 found queued "leader-elected" hook
2023-09-14 12:26:53 INFO juju.worker.uniter.operation runhook.go:186 ran "leader-elected" hook (via hook dispatching script: dispatch)
2023-09-14 12:26:54 INFO juju.worker.uniter.operation runhook.go:186 ran "config-changed" hook (via hook dispatching script: dispatch)
2023-09-14 12:26:54 INFO juju.worker.uniter resolver.go:165 found queued "start" hook
2023-09-14 12:26:54 INFO unit.postgresql/0.juju-log server.go:325 Running legacy hooks/start.
2023-09-14 12:26:55 INFO juju.worker.uniter.operation runhook.go:186 ran "start" hook (via hook dispatching script: dispatch)
2023-09-14 12:26:56 INFO juju.worker.uniter.operation runhook.go:186 ran "database-peers-relation-changed" hook (via hook dispatching script: dispatch)
2023-09-14 12:28:54 WARNING unit.postgresql/0.juju-log server.go:325 No relation: certificates
2023-09-14 12:28:54 INFO juju.worker.uniter.operation runhook.go:186 ran "update-status" hook (via hook dispatching script: dispatch)

Versions

Operating system: Ubuntu 22.04

Log output

As above.

Additional context

It looks like directly related to the snapd version.

ubuntu@test-pgsql-0:~$ sudo snap list
Name                Version        Rev    Tracking       Publisher        Notes
charmed-postgresql  14.7           31     latest/stable  dataplatformbot  held
core20              20230622       1974   latest/stable  canonical✓       base
core22              20230801       864    latest/stable  canonical✓       base
lxd                 5.0.2-838e1b2  24322  5.0/stable/…   canonical✓       -
snapd               2.59.5         19457  latest/stable  canonical✓       snapd
ubuntu@test-pgsql-0:~$ sudo /usr/lib/snapd//snap-seccomp compile /var/lib/snapd/seccomp/bpf/snap.charmed-postgresql.patroni.src /var/lib/snapd/seccomp/bpf/snap.charmed-postgresql.patroni.bin

-> no error

#
# refresh snapd to 2.60.3
# 
ubuntu@test-pgsql-0:~$ sudo snap refresh
2023-09-14T10:24:32Z INFO Waiting for automatic snapd restart...
core20 20230801 from Canonical✓ refreshed
snapd 2.60.3 from Canonical✓ refreshed
ubuntu@test-pgsql-0:~$ sudo snap list                                                                                                                                                                                                                                                                                                                                                                                                  
Name                Version        Rev    Tracking       Publisher        Notes
charmed-postgresql  14.7           31     latest/stable  dataplatformbot  held
core20              20230801       2015   latest/stable  canonical✓       base
core22              20230801       864    latest/stable  canonical✓       base
lxd                 5.0.2-838e1b2  24322  5.0/stable/…   canonical✓       -
snapd               2.60.3         20092  latest/stable  canonical✓       snapd
ubuntu@test-pgsql-0:~$ sudo /usr/lib/snapd//snap-seccomp compile /var/lib/snapd/seccomp/bpf/snap.charmed-postgresql.patroni.src /var/lib/snapd/seccomp/bpf/snap.charmed-postgresql.patroni.bin 
error: cannot parse line: cannot parse token "KCMP_FILE" (line "kcmp - - KCMP_FILE")
github-actions[bot] commented 1 year ago

https://warthogs.atlassian.net/browse/DPE-2608

dragomirp commented 1 year ago

Hi, @nobuto-m, this was a workaround that has since been removed on 14/edge, but I cannot say when those changes will land in 14/stable. Does this error happen persistently for you? Is it blocking you?

nobuto-m commented 1 year ago

This was a part of the charm deployment and it didn't go any further after hitting into this parse error.

Do you mean the snap channel or charm channel by 14/edge?

dragomirp commented 1 year ago

Do you mean the snap channel or charm channel by 14/edge?

Both. The charm holds the update of the snap, so charm 14/stable uses an old revision of the snap. Can you retry deploying 14/edge of the charm?

phvalguima commented 1 year ago

Hi @nobuto-m @dragomirp

@dragomirp is referring to a patch that was manually applied to charmed-postgresql by the charm and removed in: https://github.com/canonical/postgresql-operator/pull/192

I don't think that manual patching is the issue here, as I can reproduce the same problem by downloading the snap myself and running the snap-seccomp command pointed by @nobuto-m

I have filed a bug on snapd: https://bugs.launchpad.net/snapd/+bug/2035866

phvalguima commented 1 year ago

After discussing with snapd team, the issue was caused by a mismatch between the /usr/lib/snapd/ and snapd's snap, that is available in: /snap/snapd/current/. When using /snap/snapd/current/usr/lib/snapd/snap-seccomp, the compilation does not error.

Therefore, the issue seen by @nobuto-m was, as pointed by @dragomirp, from the operator code, that was using the DEB: /usr/lib/snapd/snap-seccomp instead of /snap/snapd/current/usr/lib/snapd/snap-seccomp.

I will close this bug. Feel free to open if the issue appears once again.

nobuto-m commented 1 year ago

Okay so when are you folks planning to release those changes to 14/stable then?

taurus-forever commented 1 year ago

Dear @nobuto-m , we have recently promoted the fixed revision 324 to 14/candidate. Can you please check it from your side and share your findings. We are performing the final stage tests here and will release it to the 14/stable soonish. Thank you for your report here!