mysql stash backup error: unexpected end of JSON input

[clayrisser]

I am getting the following error when trying to run the stash mysql backup.

F0828 08:39:24.890229 1 main.go:24] error: unexpected end of JSON input

Please note I am using the stash-mysql chart from the following repo.
https://github.com/codejamninja/stash-mysql

I am doing this because of the following error.
#879

Here is the full log output

I0828 08:39:18.460570 1 log.go:172] FLAG: --alsologtostderr="false"
I0828 08:39:18.460675 1 log.go:172] FLAG: --app-binding="mysql-c6qnp-mysql-mysql"
I0828 08:39:18.460684 1 log.go:172] FLAG: --bucket="codejamninja-backups"
I0828 08:39:18.460692 1 log.go:172] FLAG: --enable-analytics="true"
I0828 08:39:18.460701 1 log.go:172] FLAG: --enable-cache="true"
I0828 08:39:18.460707 1 log.go:172] FLAG: --enable-status-subresource="false"
I0828 08:39:18.460715 1 log.go:172] FLAG: --endpoint="s3.amazonaws.com"
I0828 08:39:18.460721 1 log.go:172] FLAG: --help="false"
I0828 08:39:18.460728 1 log.go:172] FLAG: --hostname="host-0"
I0828 08:39:18.460740 1 log.go:172] FLAG: --kubeconfig=""
I0828 08:39:18.460748 1 log.go:172] FLAG: --log-flush-frequency="5s"
I0828 08:39:18.460755 1 log.go:172] FLAG: --log_backtrace_at=":0"
I0828 08:39:18.460798 1 log.go:172] FLAG: --log_dir=""
I0828 08:39:18.460805 1 log.go:172] FLAG: --logtostderr="true"
I0828 08:39:18.460814 1 log.go:172] FLAG: --master=""
I0828 08:39:18.460821 1 log.go:172] FLAG: --max-connections="0"
I0828 08:39:18.460827 1 log.go:172] FLAG: --metrics-dir=""
I0828 08:39:18.460834 1 log.go:172] FLAG: --metrics-enabled="true"
I0828 08:39:18.460842 1 log.go:172] FLAG: --metrics-labels="[]"
I0828 08:39:18.460850 1 log.go:172] FLAG: --metrics-pushgateway-url="http://stash.kube-system.svc:56789"
I0828 08:39:18.460857 1 log.go:172] FLAG: --mysql-args="--all-databases"
I0828 08:39:18.460864 1 log.go:172] FLAG: --namespace="mysql-v9cf2"
I0828 08:39:18.460871 1 log.go:172] FLAG: --output-dir="/tmp/output"
I0828 08:39:18.460878 1 log.go:172] FLAG: --path="/mysql-v9cf2/mysql/mysql-c6qnp-mysql-mysql"
I0828 08:39:18.460885 1 log.go:172] FLAG: --provider="s3"
I0828 08:39:18.460892 1 log.go:172] FLAG: --rest-server-url=""
I0828 08:39:18.460899 1 log.go:172] FLAG: --retention-dry-run="false"
I0828 08:39:18.460906 1 log.go:172] FLAG: --retention-keep-daily="0"
I0828 08:39:18.460913 1 log.go:172] FLAG: --retention-keep-hourly="0"
I0828 08:39:18.460919 1 log.go:172] FLAG: --retention-keep-last="0"
I0828 08:39:18.460926 1 log.go:172] FLAG: --retention-keep-monthly="0"
I0828 08:39:18.460961 1 log.go:172] FLAG: --retention-keep-tags="[]"
I0828 08:39:18.460968 1 log.go:172] FLAG: --retention-keep-weekly="0"
I0828 08:39:18.460975 1 log.go:172] FLAG: --retention-keep-yearly="0"
I0828 08:39:18.460982 1 log.go:172] FLAG: --retention-prune="false"
I0828 08:39:18.460988 1 log.go:172] FLAG: --scratch-dir="/tmp"
I0828 08:39:18.460995 1 log.go:172] FLAG: --secret-dir="***REDACTED***"
I0828 08:39:18.461002 1 log.go:172] FLAG: --service-name="stash-operator"
I0828 08:39:18.461009 1 log.go:172] FLAG: --stderrthreshold="0"
I0828 08:39:18.461016 1 log.go:172] FLAG: --use-kubeapiserver-fqdn-for-aks="true"
I0828 08:39:18.461023 1 log.go:172] FLAG: --v="0"
I0828 08:39:18.461030 1 log.go:172] FLAG: --vmodule=""
W0828 08:39:18.575236 1 client_config.go:549] Neither --kubeconfig nor --master was specified. Using the inClusterConfig. This might not work.
I0828 08:39:18.584107 1 utils.go:12] Checking database connection
I0828 08:39:18.584721 1 commands.go:63] Ensuring restic repository in the backend
[golang-sh]$ /bin/restic_0.9.5 snapshots --json --cache-dir /tmp/restic-cache
I0828 08:39:20.111777 1 commands.go:343] sh-output: [{"time":"2019-08-28T08:39:11.846054909Z","tree":"69eb417f8d82e5829b96d87868a1cde14aa056aea3286531fb97d589393380e0","paths":["/tmp/dumpfile.sql"],"hostname":"host-0","username":"nobody","uid":65534,"gid":65534,"id":"bd97dad71676d228187032ba3aff650c2538eb5961efed1fbab4f3aa80f9d610","short_id":"bd97dad7"}]
I0828 08:39:20.111803 1 commands.go:98] Backing up stdin data
[golang-sh]$ mysqldump -u root -h mysql-c6qnp-mysql-mysql --all-databases | /bin/restic_0.9.5 backup --stdin --quiet --json --stdin-filename dumpfile.sql --host host-0 --cache-dir /tmp/restic-cache --cleanup-cache
I0828 08:39:22.023945 1 commands.go:343] sh-output: {"message_type":"status","percent_done":0,"total_files":1}
{"message_type":"status","percent_done":0,"total_files":1,"bytes_done":866687,"current_files":["/dumpfile.sql"]}
{"message_type":"status","percent_done":0,"total_files":1,"bytes_done":2028301,"current_files":["/dumpfile.sql"]}
{"message_type":"status","percent_done":0,"total_files":1,"bytes_done":2939112,"current_files":["/dumpfile.sql"]}
{"message_type":"status","percent_done":0,"total_files":1,"bytes_done":3571855,"current_files":["/dumpfile.sql"]}
{"message_type":"summary","files_new":0,"files_changed":1,"files_unmodified":0,"dirs_new":0,"dirs_changed":0,"dirs_unmodified":0,"data_blobs":1,"tree_blobs":1,"data_added":633246,"total_files_processed":1,"total_bytes_processed":0,"total_duration":0.812335904,"snapshot_id":"f019f72a"}
I0828 08:39:22.024321 1 commands.go:247] Checking integrity of repository
[golang-sh]$ /bin/restic_0.9.5 check --cache-dir /tmp/restic-cache
I0828 08:39:23.550009 1 commands.go:343] sh-output: using temporary cache in /tmp/restic-cache/restic-check-cache-740092776
created new cache in /tmp/restic-cache/restic-check-cache-740092776
create exclusive lock for repository
load indexes
check all packs
check snapshots, trees and blobs
no errors were found
I0828 08:39:23.550044 1 commands.go:125] Cleaning old snapshots according to retention policy
[golang-sh]$ /bin/restic_0.9.5 forget --quiet --json --cache-dir /tmp/restic-cache
I0828 08:39:24.886907 1 commands.go:343] sh-output:
Error: unexpected end of JSON input
Usage:
stash-mysql backup-mysql [flags]
Flags:
--app-binding string Name of the app binding
--bucket string Name of the cloud bucket/container (keep empty for local backend)
--enable-cache Specify whether to enable caching for restic
--endpoint string Endpoint for s3/s3 compatible backend
-h, --help help for backup-mysql
--hostname string Name of the host machine (default "host-0")
--kubeconfig string Path to kubeconfig file with authorization information (the master location is set by the master flag).
--master string The address of the Kubernetes API server (overrides any value in kubeconfig)
--max-connections int Specify maximum concurrent connections for GCS, Azure and B2 backend
--metrics-dir string Directory where to write metric.prom file (keep empty if you don't want to write metric in a text file)
--metrics-enabled Specify whether to export Prometheus metrics
--metrics-labels strings Labels to apply in exported metrics
--metrics-pushgateway-url string Pushgateway URL where the metrics will be pushed
--mysql-args string Additional arguments (default "--all-databases")
--namespace string Namespace of Backup/Restore Session (default "default")
--output-dir string Directory where output.json file will be written (keep empty if you don't need to write output in file)
--path string Directory inside the bucket where backup will be stored
--provider string Backend provider (i.e. gcs, s3, azure etc)
--rest-server-url string URL for rest backend
--retention-dry-run Specify whether to test retention policy without deleting actual data
--retention-keep-daily int Specify value for retention strategy
--retention-keep-hourly int Specify value for retention strategy
--retention-keep-last int Specify value for retention strategy
--retention-keep-monthly int Specify value for retention strategy
--retention-keep-tags strings Specify value for retention strategy
--retention-keep-weekly int Specify value for retention strategy
--retention-keep-yearly int Specify value for retention strategy
--retention-prune Specify whether to prune old snapshot data
--scratch-dir string Temporary directory (default "/tmp")
--secret-dir string Directory where storage secret has been mounted
Global Flags:
--alsologtostderr log to standard error as well as files
--enable-analytics Send analytical events to Google Analytics (default true)
--enable-status-subresource If true, uses sub resource for crds.
--log-flush-frequency duration Maximum number of seconds between log flushes (default 5s)
--log_backtrace_at traceLocation when logging hits line file:N, emit a stack trace (default :0)
--log_dir string If non-empty, write log files in this directory
--logtostderr log to standard error instead of files (default true)
--service-name string Stash service name. (default "stash-operator")
--stderrthreshold severity logs at or above this threshold go to stderr
--use-kubeapiserver-fqdn-for-aks if true, uses kube-apiserver FQDN for AKS cluster to workaround https://github.com/Azure/AKS/issues/522 (default true)
-v, --v Level log level for V logs
--vmodule moduleSpec comma-separated list of pattern=N settings for file-filtered logging
F0828 08:39:24.890229 1 main.go:24] error: unexpected end of JSON input

[clayrisser]

Surprisingly, it is creating the restic backups, but it is not completing correctly in kubernetes.

Notice the s3 restic snapshots

Notice there is no LAST-SUCCESSFUL-BACKUP

NAMESPACE     NAME                            INTEGRITY   SIZE   SNAPSHOT-COUNT   LAST-SUCCESSFUL-BACKUP   AGE
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql                                                                8m22s

Notice all the BackupSessions stuck in the running state

NAMESPACE     NAME                                       BACKUPCONFIGURATION             PHASE     AGE
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981487   mysql-mysql-c6qnp-mysql-mysql   Failed    9m55s
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981542   mysql-mysql-c6qnp-mysql-mysql   Running   9m
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981602   mysql-mysql-c6qnp-mysql-mysql   Running   8m
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981662   mysql-mysql-c6qnp-mysql-mysql   Running   7m
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981722   mysql-mysql-c6qnp-mysql-mysql   Running   6m
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981782   mysql-mysql-c6qnp-mysql-mysql   Running   5m
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981843   mysql-mysql-c6qnp-mysql-mysql   Running   3m59s
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981903   mysql-mysql-c6qnp-mysql-mysql   Running   2m59s
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566981963   mysql-mysql-c6qnp-mysql-mysql   Running   119s
mysql-v9cf2   mysql-mysql-c6qnp-mysql-mysql-1566982023   mysql-mysql-c6qnp-mysql-mysql   Running   59s

Name:         mysql-mysql-c6qnp-mysql-mysql-1566982023
Namespace:    mysql-v9cf2
Labels:       app.kubernetes.io/component=stash-backup
              app.kubernetes.io/managed-by=stash.appscode.com
              stash.appscode.com/backup-configuration=mysql-mysql-c6qnp-mysql-mysql
Annotations:  <none>
API Version:  stash.appscode.com/v1beta1
Kind:         BackupSession
Metadata:
  Creation Timestamp:  2019-08-28T08:47:03Z
  Generation:          1
  Owner References:
    API Version:           stash.appscode.com/v1beta1
    Block Owner Deletion:  false
    Kind:                  BackupConfiguration
    Name:                  mysql-mysql-c6qnp-mysql-mysql
    UID:                   1925e431-c96f-11e9-865a-06d69e0f0b3e
  Resource Version:        149568
  Self Link:               /apis/stash.appscode.com/v1beta1/namespaces/mysql-v9cf2/backupsessions/mysql-mysql-c6qnp-mysql-mysql-1566982023
  UID:                     682f2999-c970-11e9-865a-06d69e0f0b3e
Spec:
  Backup Configuration:
    Name:  mysql-mysql-c6qnp-mysql-mysql
Status:
  Phase:        Running
  Total Hosts:  1
Events:
  Type    Reason                   Age    From                      Message
  ----    ------                   ----   ----                      -------
  Normal  BackupSessionJobCreated  2m31s  BackupSession Controller  backup job has been created succesfully for BackupSession mysql-v9cf2/mysql-mysql-c6qnp-mysql-mysql-1566982023

[clayrisser]

Any ideas???

[hossainemruz]

@codejamninja can you please share the YAML for BackupConfiguration? It seems you haven't specified RetentionPolicy.

[clayrisser]

Oh yeah I commented that out. Thanks. Didn't realize that was an issue.

[hossainemruz]

If the problem is solved, please close this issue.

[clayrisser]

Sure thing

[clayrisser]

The reason I removed the retention policy is because I get the following error from stash-operator.

E0903 20:44:24.976035 1 worker.go:76] Failed to process key postgres-xf4k8/postgres-tl77q-postgres-postgres. Reason: v1beta1.BackupBlueprint.Spec: v1beta1.BackupBlueprintSpec.RetentionPolicy: v1alpha1.RetentionPolicy.KeepLast: readUint64: unexpected character: �, error found in #10 byte of ...|eepLast":"5","name":|..., bigger context ...|-postgres-backup"},"retentionPolicy":{"keepLast":"5","name":"retention-policy","prune":true},"schedu|...
I0903 20:44:24.976053 1 worker.go:80] Error syncing key postgres-xf4k8/postgres-tl77q-postgres-postgres: v1beta1.BackupBlueprint.Spec: v1beta1.BackupBlueprintSpec.RetentionPolicy: v1alpha1.RetentionPolicy.KeepLast: readUint64: unexpected character: �, error found in #10 byte of ...|eepLast":"5","name":|..., bigger context ...|-postgres-backup"},"retentionPolicy":{"keepLast":"5","name":"retention-policy","prune":true},"schedu|...

Here is the backupblueprint I am providing.

Name:         postgres-tl77q-postgres-kubedb
Namespace:    
Labels:       app=postgres-kubedb
              chart=postgres-0.0.1
              heritage=Tiller
              io.cattle.field/appId=postgres-tl77q
              release=postgres-tl77q
Annotations:  <none>
API Version:  stash.appscode.com/v1beta1
Kind:         BackupBlueprint
Metadata:
  Creation Timestamp:  2019-09-03T20:34:31Z
  Generation:          2
  Resource Version:    835460
  Self Link:           /apis/stash.appscode.com/v1beta1/backupblueprints/postgres-tl77q-postgres-kubedb
  UID:                 3bd2c98e-ce8a-11e9-865a-06d69e0f0b3e
Spec:
  Backend:
    S 3:
      Bucket:             codejamninja-backups
      Endpoint:           s3.amazonaws.com
      Prefix:             /${TARGET_NAMESPACE}/${TARGET_APP_RESOURCE}/${TARGET_NAME}
    Storage Secret Name:  postgres-tl77q-postgres-backup
  Retention Policy:
    Keep Last:  5
    Name:       retention-policy
    Prune:      true
  Schedule:     * * * * *
  Task:
    Name:  ${TARGET_APP_RESOURCE}-backup-${TARGET_APP_VERSION}
Events:    <none>

[clayrisser]

Ok, it turns out I was setting Keep Last to a string