Vvv: Can't get a fresh install working - troubles with MariaDB

[theukedge]

Expected Behavior

I would expect the provisioning process to complete without errors.

Current Behavior

I previously had VVV installed and wanted to start fresh for reasons. So I uninstalled Vagrant, VirtualBox and removed the former vagrant-local folder in its entirety. I restarted my Mac, reinstalled Vagrant 2.2.4 and VirtualBox 6.0.8.

When I cloned VVV, installed the vagrant-hostsupdater and provisioned the server for the first time, the whole process ultimately errored out and exited. Along the way, I did receive the following errors (not whether they're related):

    default: grep:
    default: /etc/apt/sources.list.d/*.list
    default: : No such file or directory

    default: Setting up mariadb-server-10.3 (1:10.3.15+maria~bionic) ...
    default: 2019-06-15  0:05:32 0 [Note] /usr/sbin/mysqld (mysqld 10.3.15-MariaDB-1:10.3.15+maria~bionic) starting as process 27289 ...
    default: 2019-06-15  0:05:32 0 [Warning] Setting lower_case_table_names=2 because file system for /var/lib/mysql/ is case insensitive
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Uses event mutexes
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Number of pools: 1
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Using SSE2 crc32 instructions
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Completed initialization of buffer pool
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
    default: 2019-06-15  0:05:32 0 [Warning] InnoDB: Failed to set O_DIRECT on file./ibdata1; OPEN: Invalid argument, continuing anyway. O_DIRECT is known to result in 'Invalid argument' on Linux on tmpfs, see MySQL Bug#26662.
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Creating shared tablespace for temporary tables
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Waiting for purge to start
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: 10.3.15 started; log sequence number 1603959; transaction id 9
    default: 2019-06-15  0:05:32 0 [Note] Plugin 'FEEDBACK' is disabled.
    default: 2019-06-15  0:05:32 0 [Note] Recovering after a crash using tc.log
    default: 2019-06-15  0:05:32 0 [ERROR] Can't init tc log
    default:
    default: 2019-06-15  0:05:32 0 [ERROR] Aborting
    default: 2019-06-15  0:05:32 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
    default: Configuring mariadb-server-10.3
    default: -------------------------------
    default:
    default: Unable to set password for the MariaDB "root" user
    default:
    default: An error occurred while setting the password for the MariaDB administrative
    default: user. This may have happened because the account already has a password, or
    default: because of a communication problem with the MariaDB server.
    default:
    default: You should check the account's password after the package installation.
    default:
    default: Please read the /usr/share/doc/mariadb-server-10.3/README.Debian file for
    default: more information.
    default: Created symlink /etc/systemd/system/mysql.service → /lib/systemd/system/mariadb.service.
    default: Created symlink /etc/systemd/system/mysqld.service → /lib/systemd/system/mariadb.service.
    default: Created symlink /etc/systemd/system/multi-user.target.wants/mariadb.service → /lib/systemd/system/mariadb.service.
    default: Job for mariadb.service failed because the control process exited with error code.
    default: See "systemctl status mariadb.service" and "journalctl -xe" for details.
    default: invoke-rc.d: initscript mysql, action "start" failed.
    default: ● mariadb.service - MariaDB 10.3.15 database server
    default:    Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
    default:   Drop-In: /etc/systemd/system/mariadb.service.d
    default:            └─migrated-from-my.cnf-settings.conf
    default:    Active: failed (Result: exit-code) since Sat 2019-06-15 00:05:38 UTC; 10ms ago
    default:      Docs: man:mysqld(8)
    default:            https://mariadb.com/kb/en/library/systemd/
    default:   Process: 28007 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
    default:   Process: 27855 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
    default:   Process: 27844 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
    default:   Process: 27823 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
    default:  Main PID: 28007 (code=exited, status=1/FAILURE)
    default: Jun 15 00:05:38 vvv mysqld[28007]: 2019-06-15  0:05:38 0 [ERROR] Could not open mysql.plugin table. Some plugins may be not loaded
    default: Jun 15 00:05:38 vvv mysqld[28007]: 2019-06-15  0:05:38 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
    default: Jun 15 00:05:38 vvv mysqld[28007]: 2019-06-15  0:05:38 6 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1017: Can't find file: './mysql/' (errno: 2 "No such file or directory")
    default: Jun 15 00:05:38 vvv mysqld[28007]: 2019-06-15  0:05:38 0 [Note] InnoDB: Buffer pool(s) load completed at 190615  0:05:38
    default: Jun 15 00:05:38 vvv mysqld[28007]: 2019-06-15  0:05:38 0 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
    default: Jun 15 00:05:38 vvv mysqld[28007]: 2019-06-15  0:05:38 0 [Note] Server socket created on IP: '127.0.0.1'.
    default: Jun 15 00:05:38 vvv mysqld[28007]: 2019-06-15  0:05:38 0 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.user' doesn't exist
    default: Jun 15 00:05:38 vvv systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
    default: Jun 15 00:05:38 vvv systemd[1]: mariadb.service: Failed with result 'exit-code'.
    default: Jun 15 00:05:38 vvv systemd[1]: Failed to start MariaDB 10.3.15 database server.
    default: dpkg: error processing package mariadb-server-10.3 (--configure):
    default:  installed mariadb-server-10.3 package post-installation script subprocess returned error exit status 1

    default: Setting up binutils (2.30-21ubuntu1~18.04.2) ...
    default: dpkg: dependency problems prevent configuration of mariadb-server:
    default:  mariadb-server depends on mariadb-server-10.3 (>= 1:10.3.15+maria~bionic); however:
    default:   Package mariadb-server-10.3 is not configured yet.
    default:
    default: dpkg: error processing package mariadb-server (--configure):
    default:  dependency problems - leaving unconfigured
    default: Setting up python-dbus (1.2.6-1) ...
    default: No apport report written because the error message indicates its a followup error from a previous failure.

and then here's how the provisioning process terminated:

    default: Processing triggers for ufw (0.36-0ubuntu0.18.04.1) ...
    default: Errors were encountered while processing:
    default:  mariadb-server-10.3
    default:  mariadb-server
    default: E: Sub-process /usr/bin/dpkg returned an error code (1)
    default: Installing apt-get packages returned a failure code, cleaning up apt caches then exiting
    default: Main packages check and install failed, halting provision
The SSH command responded with a non-zero exit status. Vagrant
assumes that this means the command failed. The output for this command
should be in the log above. Please read the output to determine what
went wrong.

Possible Solution

Clearing this has to do with the changes to how MariaDB is packaged in v3.0, but as for what the solution is, I'm at a loss.

Steps to Reproduce

1. Remove previous instances of Vagrant, VirtualBox and VVV
2. Install everything fresh
3. Provision a new server

Full provisioning output

Context

Tried uninstalling and reinstalling VVV. I have tried on both the develop and the master branch.

Your Environment

• VVV version: v3.1.0-git::develop
• VVV Git Branch: both develop and master
• Vagrant version: 2.2.4
• VM Provider name: VirtualBox
• VM Provider version: 6.0.8
• Operating System and version: macOS Mojave 10.14.5

[kmgalanakis]

I'm facing the exact same issue.

[tomjn]

Is this a new VM? If it's an existing VM, destroy it and recreate it. If it's a new VM, disable the shared database folder in vvv-custom.yml then destroy the VM and recreate it, e.g.

general:
  db_share_type: false

But, before you do so, run vagrant ssh -c "id mysql" and tell me the output for debugging purposes

[kmgalanakis]

In my case, it was an existing VM, which was destroyed and recreated. Or at least I tried to recreate it.

Here is what you asked (from the recreated VM).

$ vagrant ssh -c "id mysql"
/home/vagrant/.bash_profile: line 56: grunt: command not found
uid=112(mysql) gid=115(mysql) groups=115(mysql),999(vboxsf)
Connection to 127.0.0.1 closed.

[tomjn]

Those values should be 9001 if you're on the develop branch, destroy and
recreate your VM with the latest commits

On Sat, 15 Jun 2019 at 14:14, Konstantinos Galanakis <
[email protected]> wrote:

In my case, it was an existing VM, which was destroyed and recreated. Or
at least I tried to recreate it.

Here is what you asked (from the recreated VM).

$ vagrant ssh -c "id mysql"
/home/vagrant/.bash_profile: line 56: grunt: command not found
uid=112(mysql) gid=115(mysql) groups=115(mysql),999(vboxsf)
Connection to 127.0.0.1 closed.

—
You are receiving this because you commented.

Reply to this email directly, view it on GitHub
https://github.com/Varying-Vagrant-Vagrants/VVV/issues/1861?email_source=notifications&email_token=AAAOLZ7M2VD4KD5EF5ZDDPTP2TTJVA5CNFSM4HYOF2SKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODXYX5YQ#issuecomment-502365922,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAAOLZ6OUWXR7TZ5FUP3ABLP2TTJVANCNFSM4HYOF2SA
.

[kmgalanakis]

Now it's this

$ vagrant ssh -c "id mysql"
/home/vagrant/.bash_profile: line 56: grunt: command not found
uid=9001(mysql) gid=9001(mysql) groups=9001(mysql),115(vboxsf)
Connection to 127.0.0.1 closed.

but it fails again with the same message on the same spot.

[tomjn]

did you disable the db shared folder via vvv-custom.yml before reprovisioning?

[theukedge]

In my case, it was a new VM, so when I ran vagrant ssh -c "id mysql", I got VM must be created before running this command. Run 'vagrant up' first. I disabled the db shared folder in vvv-custom.yml and ran the provisioning process again. Once the VM was up, I ran the command again and got:

Daves-MacBook-Pro:VVV Dave$ vagrant ssh -c "id mysql"
uid=9001(mysql) gid=9001(mysql) groups=9001(mysql),115(vboxsf)
Connection to 127.0.0.1 closed.

What is the idea behind disabling the shared database folder? Is this just a temporary fix that should get fixed to where we will remove that flag in vvv-custom.yml eventually?

[tomjn]

What is the idea behind disabling the shared database folder?

It eliminates the shared folder as a possible cause. Now that you've reprovisioned does it work?

[kmgalanakis]

For me destroying the machine, disabling the shared folder and running
vagrant up - - provision solved the problem.

Regarding the shared db folder, I couldn't find any documentation. What is
it used for? Do you think I could enable it back?

Thanks

Konstantinos G.

On Sun, Jun 16, 2019, 15:02 Tom J Nowell [e-mail] wrote:

What is the idea behind disabling the shared database folder?

It eliminates the shared folder as a possible cause. Now that you've
reprovisioned does it work?

—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub
https://github.com/Varying-Vagrant-Vagrants/VVV/issues/1861?email_source=notifications&email_token=AAJVS6OTFX6JGJGGPJYVSZ3P2YTVJA5CNFSM4HYOF2SKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODXZLQBA#issuecomment-502446084,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAJVS6KKTO3SQSPRP5MPNHTP2YTVJANCNFSM4HYOF2SA
.

[theukedge]

Disabling the shared folder and reprovisioning also worked for me. I have the same question as @kmgalanakis about what it's for, what the differences are and whether the long-term plan would be to fix this issue and remove that shared folder key, or to leave it this way, and if so, what effect that would have?

Thankss

[tomjn]

In VVV 2 we stored the MariaDB data folder inside the VM, but this lead to a trade off. If you ran vagrant destroy, the database would be deleted with the VM, and on the next vagrant up, when the VM was recreated from a blank slate, the DB would be a blank slate too.

To mitigate that, we added the backup and restore scripts, otherwise most users would never have to worry about it.

With VVV 3, we undid that change, and mounted the database/data subfolder into the VM. Now, destroying and recreating the VM no longer deletes the database, as it's stored on the host machine, not the guest VM. This was done so that we could pre-package everything in our own box and have users update easily with a vagrant destroy --force; vagrant box update; vagrant up

The problem here is that for whatever reason, MariaDB doesn't like that on your instance. That's why the option to change it back to VVV 2 style database folders was added.

If you undo that change and reprovision, the database folder inside the VM will be swapped for the one on your host computer, so back up first. Ideally this option wouldn't be necessary. I've made improvements since it was introduced to increase compatibility, but that doesn't seem to solve it for all people, so there's more investigation to do.

There's also the rare edge case when the database fails to install on provision even with the shared folder disabled. I don't know the cause of this, but thankfully it's a rare issue. Recreating the VM fresh fixes it for some people, which implies the problem is to do with baggage left over from previous provisions that failed

[kmgalanakis]

After using my VM for almost a day, I got this weird error in my WP error log:

[18-Jun-2019 12:59:25 UTC] WordPress database error Disk full (/tmp/#sql_12a6_0.MAI); waiting for someone to free some space... (errno: 28 "No space left on device") for query SHOW FULL COLUMNS FROM `wp_postmeta` made by do_action('wp_ajax_heartbeat'), WP_Hook->do_action, WP_Hook->apply_filters, wp_ajax_heartbeat, apply_filters('heartbeat_received'), WP_Hook->apply_filters, wp_refresh_post_lock, wp_set_post_lock, update_post_meta, update_metadata

also when running df -h in my machine using SSH, I saw that /dev/sda1 was using 100% of its space.

Do you think that this issue is related to what we did here?

[kmgalanakis]

Also if it helps, when I'm not setting db_share_type to false, there is this strange error before the error that terminates the machine creation.

default: Configuring mariadb-server-10.3
    default: -------------------------------
    default:
    default: Unable to set password for the MariaDB "root" user
    default:
    default: An error occurred while setting the password for the MariaDB administrative
    default: user. This may have happened because the account already has a password, or
    default: because of a communication problem with the MariaDB server.
    default:
    default: You should check the account's password after the package installation.
    default:
    default: Please read the /usr/share/doc/mariadb-server-10.3/README.Debian file for
    default: more information.
    default: Created symlink /etc/systemd/system/mysql.service → /lib/systemd/system/mariadb.service.
    default: Created symlink /etc/systemd/system/mysqld.service → /lib/systemd/system/mariadb.service.
    default: Created symlink /etc/systemd/system/multi-user.target.wants/mariadb.service → /lib/systemd/system/mariadb.service.
    default: Job for mariadb.service failed because the control process exited with error code.
    default: See "systemctl status mariadb.service" and "journalctl -xe" for details.
    default: invoke-rc.d: initscript mysql, action "start" failed.
    default: ● mariadb.service - MariaDB 10.3.16 database server
    default:    Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
    default:   Drop-In: /etc/systemd/system/mariadb.service.d
    default:            └─migrated-from-my.cnf-settings.conf
    default:    Active: failed (Result: exit-code) since Tue 2019-06-18 15:18:49 UTC; 9ms ago
    default:      Docs: man:mysqld(8)
    default:            https://mariadb.com/kb/en/library/systemd/
    default:   Process: 27774 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
    default:   Process: 27626 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
    default:   Process: 27620 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
    default:   Process: 27608 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
    default:  Main PID: 27774 (code=exited, status=1/FAILURE)
    default:
    default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [ERROR] Could not open mysql.plugin table. Some plugins may be not loaded
    default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
    default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 6 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1017: Can't find file: './mysql/' (errno: 2 "No such file or directory")
    default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [Note] InnoDB: Buffer pool(s) load completed at 190618 15:18:49
    default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
    default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [Note] Server socket created on IP: '127.0.0.1'.
    default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.user' doesn't exist
    default: Jun 18 15:18:49 vvv systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE
    default: Jun 18 15:18:49 vvv systemd[1]: mariadb.service: Failed with result 'exit-code'.
    default: Jun 18 15:18:49 vvv systemd[1]: Failed to start MariaDB 10.3.16 database server.
    default: dpkg: error processing package mariadb-server-10.3 (--configure):
    default:
    default:  installed mariadb-server-10.3 package post-installation script subprocess returned error exit status 1

[tomjn]

Can you raise new issues for the new issues? I know it's nice to have a
common narrative but it's difficult to track. I'm in Berlin doing
everything over my phone at the moment

The disk error sounds like you ran out of free space on your computer

The other one is database related, when you open the new issue put the full
log in there as well as wether things were loading after provision

On Tue, 18 Jun 2019 at 17:21, Konstantinos Galanakis <
[email protected]> wrote:

Also if it helps, when I'm not setting db_share_type to false, there is
this strange error before the error that terminates the machine creation.

default: Configuring mariadb-server-10.3

default: -------------------------------

default:

default: Unable to set password for the MariaDB "root" user

default:

default: An error occurred while setting the password for the MariaDB administrative

default: user. This may have happened because the account already has a password, or

default: because of a communication problem with the MariaDB server.

default:

default: You should check the account's password after the package installation.

default:

default: Please read the /usr/share/doc/mariadb-server-10.3/README.Debian file for

default: more information.

default: Created symlink /etc/systemd/system/mysql.service → /lib/systemd/system/mariadb.service.

default: Created symlink /etc/systemd/system/mysqld.service → /lib/systemd/system/mariadb.service.

default: Created symlink /etc/systemd/system/multi-user.target.wants/mariadb.service → /lib/systemd/system/mariadb.service.

default: Job for mariadb.service failed because the control process exited with error code.

default: See "systemctl status mariadb.service" and "journalctl -xe" for details.

default: invoke-rc.d: initscript mysql, action "start" failed.

default: ● mariadb.service - MariaDB 10.3.16 database server

default:    Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)

default:   Drop-In: /etc/systemd/system/mariadb.service.d

default:            └─migrated-from-my.cnf-settings.conf

default:    Active: failed (Result: exit-code) since Tue 2019-06-18 15:18:49 UTC; 9ms ago

default:      Docs: man:mysqld(8)

default:            https://mariadb.com/kb/en/library/systemd/

default:   Process: 27774 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)

default:   Process: 27626 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)

default:   Process: 27620 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)

default:   Process: 27608 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)

default:  Main PID: 27774 (code=exited, status=1/FAILURE)

default:

default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [ERROR] Could not open mysql.plugin table. Some plugins may be not loaded

default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool

default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 6 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1017: Can't find file: './mysql/' (errno: 2 "No such file or directory")

default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [Note] InnoDB: Buffer pool(s) load completed at 190618 15:18:49

default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist

default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [Note] Server socket created on IP: '127.0.0.1'.

default: Jun 18 15:18:49 vvv mysqld[27774]: 2019-06-18 15:18:49 0 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.user' doesn't exist

default: Jun 18 15:18:49 vvv systemd[1]: mariadb.service: Main process exited, code=exited, status=1/FAILURE

default: Jun 18 15:18:49 vvv systemd[1]: mariadb.service: Failed with result 'exit-code'.

default: Jun 18 15:18:49 vvv systemd[1]: Failed to start MariaDB 10.3.16 database server.

default: dpkg: error processing package mariadb-server-10.3 (--configure):

default:

default:  installed mariadb-server-10.3 package post-installation script subprocess returned error exit status 1

—
You are receiving this because you commented.

Reply to this email directly, view it on GitHub
https://github.com/Varying-Vagrant-Vagrants/VVV/issues/1861?email_source=notifications&email_token=AAAOLZ63TK5IL5YVYSRBOLTP3D4PJA5CNFSM4HYOF2SKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODX67X2Y#issuecomment-503184363,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAAOLZ7ALIILWWUO2DF76WLP3D4PJANCNFSM4HYOF2SA
.

[Mte90]

Can you try the develop branch version now?

[kmgalanakis]

OK, now the develop branch has db_share_type: false by default, so instead of adding it ourselves, now it's the default option. I don't see why this won't work but it doesn't solve the actual problem, that with db_share_type: true won't allow successful provisioning.

[tomjn]

You can set it to true, but I changed that to false by default myself, if you think about it even if it works for 90% of users just fine, that's still 10% of people who have to change it to false which isn't a great experience.

I'd really like it to work flawlessly with shared folders, but reliability should take a higher priority. Local dev environments should just work. Having said that any improvements we can make would be awesome.

[kmgalanakis]

@tomjn this makes total sense to me and I fully agree with you.

Is there any other way you can think of that I could possibly debug the issue with db_share_type: true?

[tomjn]

At the moment no, a little time to think is what's needed

[kmgalanakis]

If by any chance you think of any possible reason why this happens, I'm willing to test whatever scenario you might think.

[theukedge]

Steps taken:

• git checkout develop
• git pull
• commented out db_share_type: false in vvv-custom.yml
• vagrant up --provision

Result: failed. Output

[benlumia007]

Hello, did you destroy the vagrant box, since I believe we are using ubuntu/bionic64 at this time! I just did a fresh install at the latest develop branch and it works fine.

[kmgalanakis]

@benlumia007 the latest develop has db_share_type: false. Try setting this to true in your vvv-custom.yml, destroy your machine and recreate it by using vagrant up --provision.

For me, this setup fails again, as nothing relevant was changed for the past 5-6 days.

[benlumia007]

right, but when db_share_type: false, it shouldn't fail, I think that's why it was added to the .yml by default to false.

[Mte90]

Can you do a check with the latest changes and a vagrant destroy?
I think that the db-share has a lot of problems, so we are now disabling as default and let people need it to enable when they want.

[kmgalanakis]

As I mentioned before the latest develop has db_share_type: false. For me, this setup was provisioning properly even before those changes.

But when db_share_type: true the provisioning fails, which is the actual issue for now.

[thomasplevy]

FWIW my clean install running on the develop branch with the db_share_type: false in the default vvv-config.yml was not working until I explicitly set db_share_type: false in the vv-custom.yml file.

Now with that in place all is good. Thanks!

[skorasaurus]

In case anyone else comes across this;

I had the same error message as well; (see line 1794) as mentioned in the original post but I tried one more round of uninstalling virtualbox and vagrant, shutdown computer and then restart, then install virtual box 5.2-30 and the extensions pack, vagrant 2.2.5, shutdown computer and then restart,

vagrant plugin install vagrant-hostsupdater &&
vagrant plugin update

ensure I had db_share_type: false in my vvv-custom.yml
did vagrant up --provision
(using the develop branch)
and was able to get back up and running

[axelson]

On the latest develop I had to set db_share_type: false as well. I'm running on Arch Linux if that makes a difference.

[benlumia007]

yes, db_share_type is set by default when you clone the repo for the first time, if your project exists already, doing a git pull should also set the db_share_type to false by default unless it was true at one point.

[tomjn]

@benlumia007 even if vvv-config.yml is updated via a git pull it won't change vvv-custom.yml which gets created on the first vagrant command

[axelson]

yes, db_share_type is set by default when you clone the repo for the first time, if your project exists already, doing a git pull should also set the db_share_type to false by default unless it was true at one point.

Ah, ok. I see now. Now when you run vagrant up for the first time a vvv-custom.yml is generated that has db_share_type: false by default. I assumed that what was meant in https://github.com/Varying-Vagrant-Vagrants/VVV/issues/1861#issuecomment-504046658 was that if vvv-custom.yml didn't include db_share_type then it would default to false. I guess when you upgrade you should compare your current vvv-custom.yml to the autogenerated one. Are there any instructions for that?

[tomjn]

If we set it to false if it wasn’t specified then people who had already
provisioned without it being set worked lose their database

On Sun, 21 Jul 2019 at 19:18, Jason Axelson [e-mail]
wrote:

yes, db_share_type is set by default when you clone the repo for the first
time, if your project exists already, doing a git pull should also set the
db_share_type to false by default unless it was true at one point.

Ah, ok. I see now. Now when you run vagrant up for the first time a
vvv-custom.yml is generated that has db_share_type: false by default. I
assumed that what was meant in #1861 (comment)
https://github.com/Varying-Vagrant-Vagrants/VVV/issues/1861#issuecomment-504046658
was that if vvv-custom.yml didn't include db_share_type then it would
default to false. I guess when you upgrade you should compare your current
vvv-custom.yml to the autogenerated one. Are there any instructions for
that?

—
You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub
https://github.com/Varying-Vagrant-Vagrants/VVV/issues/1861?email_source=notifications&email_token=AAAOLZ4XYBCDUNDH7VIXCO3QASR57A5CNFSM4HYOF2SKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD2OIZEY#issuecomment-513576083,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AAAOLZY2ZD5HFQGCKMLTRU3QASR57ANCNFSM4HYOF2SA
.

[benlumia007]

Ooops!, that was my mistake. that's what i meant @axelson, i must have mistype a few things and just forgot to proofread lol.

[killerbishop]

I'm having this exact same issue. Unlike the OP, however, I'm running with the _hyperv_ provider. I am running off of the _develop_ branch with db_share_type: false - however - the package for MariaDB dies the same way. The errors stem from some configuration issue with auto-extending ibdata1:

    default: After this operation, 0 B of additional disk space will be used.
    default: Setting up mariadb-server-10.3 (1:10.3.18+maria~bionic) ...
    default: 2019-09-17 18:50:19 0 [Note] /usr/sbin/mysqld (mysqld 10.3.18-MariaDB-1:10.3.18+maria~bionic) starting as process 12655 ...
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: Uses event mutexes
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: Number of pools: 1
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: Using SSE2 crc32 instructions
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: Completed initialization of buffer pool
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
    default: 2019-09-17 18:50:19 0 [ERROR] InnoDB: The Auto-extending innodb_system data file './ibdata1' is of a different size 0 pages than specified in the .cnf file: initial 768 pages, max 0 (relevant if non-zero) pages!
    default: 2019-09-17 18:50:19 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
    default: 2019-09-17 18:50:19 0 [Note] InnoDB: Starting shutdown...
    default: 2019-09-17 18:50:20 0 [ERROR] Plugin 'InnoDB' init function returned error.
    default: 2019-09-17 18:50:20 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
    default: 2019-09-17 18:50:20 0 [Note] Plugin 'FEEDBACK' is disabled.
    default: ERROR: 1049  Unknown database 'mysql'
    default: 2019-09-17 18:50:20 0 [ERROR] Aborting
    default: Configuring mariadb-server-10.3
    default: -------------------------------
    default:
    default: Unable to set password for the MariaDB "root" user
    default:
    default: An error occurred while setting the password for the MariaDB administrative
    default: user. This may have happened because the account already has a password, or
    default: because of a communication problem with the MariaDB server.
    default:
    default: You should check the account's password after the package installation.
    default:
    default: Please read the /usr/share/doc/mariadb-server-10.3/README.Debian file for
    default: more information.
    default: Job for mariadb.service failed because the control process exited with error code.
    default: See "systemctl status mariadb.service" and "journalctl -xe" for details.
    default: invoke-rc.d: initscript mysql, action "start" failed.
    default: ● mariadb.service - MariaDB 10.3.18 database server
    default:    Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
    default:   Drop-In: /etc/systemd/system/mariadb.service.d
    default:            └─migrated-from-my.cnf-settings.conf
    default:    Active: failed (Result: exit-code) since Tue 2019-09-17 18:50:22 UTC; 7ms ago
    default:      Docs: man:mysqld(8)
    default:            https://mariadb.com/kb/en/library/systemd/
    default:   Process: 12918 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
    default:   Process: 12773 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
    default:   Process: 12765 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
    default:   Process: 12753 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
    default:  Main PID: 12918 (code=exited, status=1/FAILURE)
    default:    Status: "MariaDB server is down"
    default: dpkg: error processing package mariadb-server-10.3 (--configure):
    default:  installed mariadb-server-10.3 package post-installation script subprocess returned error exit status 1
    default: dpkg: dependency problems prevent configuration of mariadb-server:
    default:  mariadb-server depends on mariadb-server-10.3 (>= 1:10.3.18+maria~bionic); however:
    default:   Package mariadb-server-10.3 is not configured yet.
    default:
    default: dpkg: error processing package mariadb-server (--configure):
    default:  dependency problems - leaving unconfigured
    default: Errors were encountered while processing:
    default:  mariadb-server-10.3
    default:  mariadb-server
    default: Installing apt-get packages returned a failure code, cleaning up apt caches then exiting
    default: Main packages check and install failed, halting provision
The SSH command responded with a non-zero exit status. Vagrant
assumes that this means the command failed. The output for this command
should be in the log above. Please read the output to determine what
went wrong.

[tomjn]

@killerbishop is this:

• an existing VM that has broken
• an existing VM that has just been updated
• a new VM that has just been provisioned

Additionally, when you mentioned that db_share_type is set to false, was this changed to false and then a brand new VM was created? Or was this done after the VM was created as a change to an already created VM? Or has this always been set to false? Or was it set as a debugging step? Keep in mind that the default value is off.

Also, can you share your VVV splash screen?

As a general note, I cannot guarantee that the VM will be 100% functional when ran with hyperv, we don't have much in the way of testers on hyperv so the first we hear that it doesn't work is when people comment in issues expecting it to work

[killerbishop]

This is a fresh install. I know it is better tested with VirtualBox and I was working with that before I had to do some stuff with Docker on my machine. Now that I am running Hyper-V, I decided to give it a go using that which looks like it was going to work until I ran into this issue.

I downloaded VVV using git, and switched to the _develop_ branch:

D:\kille>git clone -b master git://github.com/Varying-Vagrant-Vagrants/VVV.git vagrant-local
Cloning into 'vagrant-local'...
remote: Enumerating objects: 61, done.
remote: Counting objects: 100% (61/61), done.
remote: Compressing objects: 100% (57/57), done.
remote: Total 10783 (delta 29), reused 2 (delta 2), pack-reused 10722R
Receiving objects: 100% (10783/10783), 7.83 MiB | 13.34 MiB/s, done.
Resolving deltas: 100% (5038/5038), done.

D:\kille>cd vagrant-local

D:\kille\vagrant-local>git checkout develop
Switched to a new branch 'develop'
Branch 'develop' set up to track remote branch 'develop' from 'origin'.

On that branch, the db_share_type: false directive is already in place as the default. I'm using the unchanged version of the _vvv-custom.yml_ file that comes with the branch. Next, I run:

vagrant up --provider=hyperv

It goes through the provisioning process, and asks which switch I want to use (I use the default - 2) and to enter a username/password for SMB. It creates the disk image and downloads a lot of packages and then produces that error and does not finish the install. I've attached the output from the process.

[benlumia007]

there were issues with using hyperv for vvv, it wouldn't matter if set the db_share_type to true or not, it would be stuck at MariaDB and never finished. we haven't figure out the root cause of it. so hyperv hasn't gone far enough to be success.

[tomjn]

Thanks for the provisioner log! I spotted this output:

    default: Job for mariadb.service failed because the control process exited with error code.
    default: See "systemctl status mariadb.service" and "journalctl -xe" for details.
    default: invoke-rc.d: initscript mysql, action "start" failed.

Can you SSH into the VM and get me the results of systemctl status mariadb.service and journalctl -xe?

[killerbishop]

@tomjn - the status didn't provide much of anything useful:

root@vvv:/etc/mysql# systemctl status mariadb.service
● mariadb.service - MariaDB 10.3.18 database server
   Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/mariadb.service.d
           └─migrated-from-my.cnf-settings.conf
   Active: failed (Result: exit-code) since Wed 2019-09-18 05:48:12 UTC; 6s ago
     Docs: man:mysqld(8)
           https://mariadb.com/kb/en/library/systemd/
  Process: 5780 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
  Process: 5635 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
  Process: 5629 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 5617 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
 Main PID: 5780 (code=exited, status=1/FAILURE)
   Status: "MariaDB server is down"

Something I did try was starting _mysqld_ directly. This did throw this error:

root@vvv:/etc/mysql# mysqld
2019-09-18  5:48:51 0 [Note] mysqld (mysqld 10.3.18-MariaDB-1:10.3.18+maria~bionic-log) starting as process 5794 ...
2019-09-18  5:48:51 0 [ERROR] mysqld: File '/var/log/mysql/mariadb-bin.index' not found (Errcode: 2 "No such file or directory")
2019-09-18  5:48:51 0 [ERROR] Aborting

The directories in /var/log are all owned by user and group _vagrant_. Permissions/ownership must be exact for the startup of the bin/index files. Trying to run chown mysql.mysql /var/log/mysql does nothing (chmod also fails) which I believe is related to that fact that this part of the mounted driver running on CIFS/SMB.
I was able to manually fix by creating a custom configuration in /etc/mysql/conf.d/zzz.cnf (I wanted to make sure it loaded last):

root@vvv:/etc/mysql/conf.d# cat zzz.cnf
[mysqld]
slow_query_log_file     = /var/lib/mysql/mariadb-slow.log
log_bin                 = /var/lib/mysql/mariadb-bin
log_bin_index           = /var/lib/mysql/mariadb-bin.index

This was just to point those locations to somewhere that the filesystem was behaving properly with user ownership and permissions. With that change, the service was able to start.

[killerbishop]

Something that may need to be added to the Vagrantfile is an override like this:

override.vm.synced_folder "log/mysql", "/var/log/mysql", create: true, owner: "mysql", group: "mysql", mount_options:[ "dir_mode=0775", "file_mode=0640" ]

Removing my custom config is booting with this change in place, but a fresh install may need to be tested again to confirm.

[benlumia007]

so did it actually finished provisioning and you can actually go to the vvv.test, etc when you use your custom configs.

[tomjn]

We should look into making that change in the vagrantfile, but I would prefer that we use the user/group IDs rather than mysql for maximum compatibility

[killerbishop]

@benlumia007 and @tomjn - I can confirm that Hyper-V did load just fine after this change and I was able to access the host. I did need to manually configure my Windows hosts file, but that's almost certainly unrelated to the general provisioning. So - yes - it works!

[benlumia007]

@killerbishop
when you do provisioning with hyperv, does it fill little sluggish when it grabs information when it downloads from the git repo. cuz i know i feel like there's sluggish when using hyperv.

[benlumia007]

@tomjn
isn't is already using the user id and group id for this case. I wonder if it's different and it fails.

[killerbishop]

Provisioning did seem to take a long time. I've straced git clone - and it seems to hang when two file openat() functions are trying to access the same file.

lstat("/srv/www/wordpress-develop/.git/config", {st_mode=S_IFREG|0774, st_size=36, ...}) = 0
readlink("/srv/www/wordpress-develop/.git/config", 0x55e5722fd910, 38) = -1 EINVAL (Invalid argument)
openat(AT_FDCWD, "/srv/www/wordpress-develop/.git/config.lock", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 3
getpid()                                = 8716
openat(AT_FDCWD, "/srv/www/wordpress-develop/.git/config", O_RDONLY) = 4
openat(AT_FDCWD, "/srv/www/wordpress-develop/.git/config", O_RDONLY

It eventually times out and moves quickly until it gets into the deadlock on the files. Maybe this is a mounting options issue with cifs?

[benlumia007]

so, im not the only one, i think is the mount options for cifs, i think i read somewhere u can fixed that, i need to find that. i'll share on here once i find it.

[killerbishop]

@benlumia007 - so mounting options definitely make a difference. My CIFS mounts were mounting as _vers=2.0_. I switched the protocol to something newer - _vers=3.0_ and the performance is night and day difference. According to the man page, mounting is suppose to auto-detect the best protocol - but that must not be working or is defaulting to an old protocol. The version I selected isn't the newest either.

[benlumia007]

@killerbishop
are u saying that version 3 works well then.

[killerbishop]

The protocol change definitely fixes issues with using git clone on a CIFS mounted drive. I'm testing provisioning right now, but that still appears to be really slow for some reason. For me, it hangs for a really long time on PHP code sniffer - here's a snippet where it just hangs with no feedback:

    default: Installing/updating wp-cli and debugging tools
    default:
    default: Updating wp-cli...
    default: Downloading from https://raw.githubusercontent.com/wp-cli/builds/gh-pages/phar/wp-cli-nightly.phar...
    default: md5 hash verified: 0da31a60c62a1f5cf129c317a1ade8e4
    default: New version works. Proceeding to replace.
    default: Success: Updated WP-CLI to the latest nightly release.
    default:
    default: Install/Update PHP_CodeSniffer (phpcs), see https://github.com/squizlabs/PHP_CodeSniffer
    default:
    default: Install/Update WordPress-Coding-Standards, sniffs for PHP_CodeSniffer, see https://github.com/WordPress-Coding-Standards/WordPress-Coding-Standards
    default: Loading composer repositories with package information

    default: Updating dependencies (including require-dev)
    default: Package operations: 6 installs, 0 updates, 0 removals
    default:   - Installing squizlabs/php_codesniffer (3.4.2):
    default: Loading from cache

[killerbishop]

Provisioning issue was because that was not mounted as 3.0 - the hyperv section of the Vagrantfile did not contain the relevant configuration items - here's what I had to add:

    override.vm.synced_folder "database/", "/srv/database", :mount_options => [ "vers=3.0" ]
    override.vm.synced_folder "config/", "/srv/config", :mount_options => [ "vers=3.0" ]
    override.vm.synced_folder "provision/", "/srv/provision", :mount_options => [ "vers=3.0" ] 
    override.vm.synced_folder "certificates/", "/srv/certificates", :mount_options => [ "vers=3.0" ]

Now it doesn't hang for very long (there's still a small hang - but I think that is because it is checking lots of things).

[benlumia007]

interesting, can you confirm if u can still write in the themes folder and plugins as well or any place that can be writable.

[killerbishop]

Seems to work - I was able to install/activate both plugins and themes. I also restarted the instance to make sure the changes persist between boots.

[benlumia007]

Cool stuff dude. I'll try and verify this on my surface pro 4 and if it works according, I'll do a Pull Request for it, @tomjn

[tomjn]

@benlumia007 did everything work out ok?

[benlumia007]

@tomjn
sorry, I got sidetracked, I'll do it over the weekend.

[benlumia007]

@tomjn
do we still have any news regarding since we believe fixed it.

[cfern87]

I hope so. I just found this via a google and have been working on this issue for two days.

Was frustrating as hell, as I've got clients waiting for me to figure out issues and that last version if VVV I was on was 2 lol.

I completely removed VBox, Vagrant, and VVV (vagrant-local directory). Reinstalled everything with defaults, worked fine.

Added my config.yml to the config folder and it gave similar database errors.

Just tried setting shared db to false, destroying the box, updating it, then vagrant up --provision, and it seems to have worked. Did a second vagrant up --provision to be sure.

I'd like to be able to run this with a shared db folder so that the db doesn't die when I kill the box.
Seems like we've arrived at a band-aid solution, and not a true one.

[tomjn]

I'm going to close this out, the shared database folder was great if it works, but the reliability is so low, and the problems so endemic that fixing it to work reliably is going to be more effort than just rebuilding vagrant and VVV itself. I can easily see this taking 5-10 years before the kinks are worked out, assuming we invest that time, and a solution is possible.

So:

• If you're having trouble provisioning, turn off the shared DB folder, in new VVV setups it is off by default
• If it works for you then great
• You can't turn this on and off on an existing already provisioned VM without major issues, which is expected
• I'd like to eliminate this, but that would be a middle finger to minority who got it working who then lose their DB on update
• The chances of this working are very, very, very low, if it doesn't work the first time, don't bother trying to rebuild/debug/etc, just disable it
• Nobody on the core team is testing and actively maintaining this feature
• I might update this so that when shared DB folders are turned on, it prints a very large warning indicating that provisioning will probably fail, and telling you to turn it off

If someone wants to invest the time and figure it out, that'd be super useful, but I think the time is better spent on alternative solutions. It's clear others have tried with VirtualBox and Docker, and nobody has arrived at a reliable solution that works for everybody.

[lock[bot]]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.