Trouble shooting MLMD schema migration about ml-metadata HOT 6 CLOSED

@ConverJens the error from the server main.cc, means the kubeflow grpc server binary is at a v6 when starting, the enable migration is disabled. Please specify the flag when starting the server

/cc @dushyanthsc for kubeflow deployment guide/best practice

from ml-metadata.

@hughmiao Thank you for your swift response!

I'm running MLMD in KubeFlow using (or trying to) image:
gcr.io/tfx-oss-public/ml_metadata_store_server:v0.25.0

I tried adding the flag as seen below but this had no effect. I still get exactly the same error message.

command: ["/bin/metadata_store_server"]
args: ["--grpc_port=$(METADATA_GRPC_SERVICE_PORT)", "--enable_database_upgrade=true"]

Any idea why that is?

@dushyanthsc
The image for KFs http deployment of MLMD (gcr.io/kubeflow-images-public/metadata:v0.1.11) seems to be out of date and only supports schema version 4. I thinks this also needs updating.

from ml-metadata.

@ConverJens thanks! What are the mysql flags are used when running the server? Would you please provide more logs when running the server?

from ml-metadata.

@hughmiao We are using vanilla Kubelow 1.1.0 on-prem installation.

The mysql database has no additional flags except data dir and it is based on mysql 8.0.3:

image: mysql:8.0.3
args: - --datadir - /var/lib/mysql/datadir

These are from the mysql server since start up:

2020-11-26T15:09:00.675840Z 0 [Note] Basedir set to /usr/
2020-11-26T15:09:00.676084Z 0 [Warning] The syntax '--symbolic-links/-s' is deprecated and will be removed in a future release
2020-11-26T15:09:00.676163Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
2020-11-26T15:09:00.676198Z 0 [Note] /usr/sbin/mysqld (mysqld 8.0.3-rc-log) starting as process 1 ...
2020-11-26T15:09:00.679592Z 0 [Warning] No argument was provided to --log-bin, and --log-bin-index was not used; so replication may break when this MySQL server acts as a master and has his hostname changed!! Please use '--log-bin=metadata-db-5f99dcf486-k4zxv-bin' to avoid this problem.
2020-11-26T15:09:00.683538Z 0 [Note] InnoDB: Using Linux native AIO
2020-11-26T15:09:00.683703Z 0 [Note] Plugin 'FEDERATED' is disabled.
2020-11-26T15:09:00.687285Z 1 [Note] InnoDB: PUNCH HOLE support available
2020-11-26T15:09:00.687340Z 1 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-11-26T15:09:00.687350Z 1 [Note] InnoDB: Uses event mutexes
2020-11-26T15:09:00.687359Z 1 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2020-11-26T15:09:00.687368Z 1 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-11-26T15:09:00.687979Z 1 [Note] InnoDB: Number of pools: 1
2020-11-26T15:09:00.688268Z 1 [Note] InnoDB: Using CPU crc32 instructions
2020-11-26T15:09:00.691993Z 1 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2020-11-26T15:09:00.710383Z 1 [Note] InnoDB: Completed initialization of buffer pool
2020-11-26T15:09:00.712392Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-11-26T15:09:00.725409Z 1 [Note] InnoDB: Using 'tablespaces.open.1' max LSN: 44782312
2020-11-26T15:09:00.727443Z 1 [Note] InnoDB: Applying a batch of 0 redo log records ...
2020-11-26T15:09:00.727476Z 1 [Note] InnoDB: Apply batch completed!
2020-11-26T15:09:00.729498Z 1 [Note] InnoDB: Opened 2 existing undo tablespaces.
2020-11-26T15:09:00.747060Z 1 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-11-26T15:09:00.747175Z 1 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-11-26T15:09:00.762785Z 1 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-11-26T15:09:00.768691Z 1 [Note] InnoDB: Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.
2020-11-26T15:09:00.769024Z 1 [Note] InnoDB: 8.0.3 started; log sequence number 44782489
2020-11-26T15:09:00.847314Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/datadir/ib_buffer_pool
2020-11-26T15:09:00.848110Z 0 [Note] InnoDB: Buffer pool(s) load completed at 201126 15:09:00
2020-11-26T15:09:00.860888Z 1 [Note] Found data dictionary with version 1
2020-11-26T15:09:00.893067Z 0 [Note] InnoDB: DDL log recovery : begin
2020-11-26T15:09:00.893193Z 0 [Note] InnoDB: DDL log recovery : end
2020-11-26T15:09:00.893770Z 0 [Note] InnoDB: Waiting for purge to start
2020-11-26T15:09:00.947790Z 0 [Warning] You have not provided a mandatory server-id. Servers in a replication topology must have unique server-ids. Please refer to the proper server start-up parameters documentation.
2020-11-26T15:09:00.950100Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2020-11-26T15:09:00.950524Z 0 [Warning] CA certificate ca.pem is self signed.
2020-11-26T15:09:00.955085Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2020-11-26T15:09:00.955154Z 0 [Note] IPv6 is available.
2020-11-26T15:09:00.955181Z 0 [Note] - '::' resolves to '::';
2020-11-26T15:09:00.955312Z 0 [Note] Server socket created on IP: '::'.
2020-11-26T15:09:00.969564Z 0 [Warning] 'user' entry 'mysql.session@localhost' ignored in --skip-name-resolve mode.
2020-11-26T15:09:00.969600Z 0 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2020-11-26T15:09:00.969616Z 0 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2020-11-26T15:09:00.969647Z 0 [Warning] 'db' entry 'performance_schema mysql.session@localhost' ignored in --skip-name-resolve mode.
2020-11-26T15:09:00.969662Z 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2020-11-26T15:09:00.969679Z 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2020-11-26T15:09:01.010992Z 0 [Warning] 'tables_priv' entry 'user mysql.session@localhost' ignored in --skip-name-resolve mode.
2020-11-26T15:09:01.011035Z 0 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
2020-11-26T15:09:01.025873Z 4 [Note] Event Scheduler: scheduler thread started with id 4
2020-11-26T15:09:01.026121Z 0 [Note] /usr/sbin/mysqld: ready for connections. Version: '8.0.3-rc-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 MySQL Community Server (GPL)
2020-11-26T15:09:31.463595Z 20 [Note] Aborted connection 20 to db: 'metadb' user: 'root' host: '10.42.2.2' (Got an error reading communication packets)
2020-11-26T15:12:14.455887Z 102 [Note] Aborted connection 102 to db: 'metadb' user: 'root' host: '10.42.2.2' (Got an error reading communication packets)
2020-11-26T15:12:35.214908Z 113 [Note] Aborted connection 113 to db: 'metadb' user: 'root' host: '10.42.3.73' (Got an error reading communication packets)
2020-11-26T15:12:35.214908Z 110 [Note] Aborted connection 110 to db: 'metadb' user: 'root' host: '10.42.3.73' (Got an error reading communication packets)
2020-11-26T15:12:35.214920Z 108 [Note] Aborted connection 108 to db: 'metadb' user: 'root' host: '10.42.3.73' (Got an error reading communication packets)

Are there any other logs that you need?

from ml-metadata.

@ConverJens thanks. I meant the grpc server start up log, and other mysql flags used when start the grpc server.

Also you can check the MLMDEnv table in the db that is configured with the grpc server, and do a select * from it to double check the value.

from ml-metadata.

please feel free to reopen/create the issue if you still have issue with this.

from ml-metadata.