MariaDB fails to restart after attempting to install nextcloud

[ghost]

Details:

• Date | Sat 25 May 20:41:42 BST 2019
• Bug report | N/A
• DietPi version | v6.24.1 (MichaIng/master)
• Img creator | DietPi Core Team
• Pre-image | Raspbian Lite
• SBC device | RPi B+ (armv6l) (index=1)
• Kernel version | General | Update VM images to Stretch #1219 Tue May 14 21:16:38 BST 2019
• Distro | stretch (index=4)
• Command | systemctl restart mariadb
• Exit code | 1
• Software title | DietPi-Software

Steps to reproduce:

1. Start with a fresh Diet-Pi install
2. Attempt to install nextcloud

Expected behaviour:

• Nextcloud installs.

Actual behaviour:

• After attempting to enable 4 byte support for MariaDB, MariaDB fails to restart.

Extra details:

• Systemctl status for mariaDB shows:

Process: 22507 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/r
un/mysqld (code=exited, status=127)
 Main PID: 2593 (code=exited, status=0/SUCCESS)

May 25 20:44:55 DietPi systemd[1]: Starting MariaDB 10.1.38 database server...
May 25 20:44:55 DietPi systemd[1]: mariadb.service: Control process exit
ed, code=exited status=127
May 25 20:44:55 DietPi systemd[1]: Failed to start MariaDB 10.1.38 datab
ase server.
May 25 20:44:55 DietPi systemd[1]: mariadb.service: Unit entered failed
state.
May 25 20:44:55 DietPi systemd[1]: mariadb.service: Failed with result '
exit-code'.

Additional logs:

Log file contents:
Job for mariadb.service failed because the control process exited with error code.
See "systemctl status mariadb.service" and "journalctl -xe" for details.

[MichaIng]

@FizzyAllison
Many thanks for your report.

I'll try to replicate.

[ghost]

@FizzyAllison
Many thanks for your report.

I'll try to replicate.

No problem! This has been bugging me for awhile now.

[MichaIng]

@FizzyAllison
Unable to replicate, MariaDB starts up fine on test machine after 4byte support enabled.

Could you please paste: cat /var/log/mysql/error.log

---

Hmm

Process: 22507 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/r
un/mysqld (code=exited, status=127)

• Unable to create run dir?

Check: ls -Al /var/run /run; which -a install

[ghost]

lrwxrwxrwx  1 root root   4 Nov 13  2018 /var/run -> /run

/run:
total 16
-rw-------  1 root     root        0 May 25 22:17 agetty.reload
drwxr-xr-x  2 root     root       60 May 25 22:17 blkid
drwxr-xr-x  2 root     root       80 May 25 22:17 console-setup
-rw-r--r--  1 root     root        5 May 25 22:26 crond.pid
----------  1 root     root        0 May 25 22:26 crond.reboot
-rw-r--r--  1 root     root        4 May 25 22:17 dhclient.eth0.pid
-rw-r--r--  1 root     root        4 May 25 22:17 dropbear.pid
lrwxrwxrwx  1 root     root       25 May 25 22:17 initctl -> /run/systemd/initctl/fifo
drwxr-x---  2 www-data www-data   40 May 25 22:17 lighttpd
drwxrwxrwt  3 root     root       60 May 25 22:17 lock
drwxr-xr-x  3 root     root       60 May 25 22:17 log
drwxr-xr-x  2 root     root       60 Nov  3  2016 mount
drwxr-xr-x  2 mysql    root       80 May 25 22:26 mysqld
drwxr-xr-x  2 root     root      120 May 25 22:17 network
drwxr-xr-x  2 www-data www-data   80 May 25 22:26 php
drwxrwsr-x  2 redis    redis      40 May 25 22:17 redis
drwxr-xr-x  3 root     root      100 May 25 22:17 resolvconf
drwxr-xr-x  2 root     root       40 May 25 22:17 sendsigs.omit.d
lrwxrwxrwx  1 root     root        8 May 25 22:17 shm -> /dev/shm
drwxr-xr-x 17 root     root      460 May 25 22:26 systemd
drwxr-xr-x  2 root     root       60 Nov  3  2016 tmpfiles.d
drwxr-xr-x  7 root     root      160 May 25 22:17 udev
drwxr-xr-x  2 root     root       40 May 25 22:17 user
-rw-rw-r--  1 root     utmp     1536 May 25 22:18 utmp
/usr/bin/install

and

cat: /var/log/mysql/error.log: No such file or directory

[MichaIng]

@FizzyAllison
Strange, command exists, directories are there, permissions correct. Actually status=127 means command not found, but it exists as expected 🤔.

systemctl stop mariadb
rm -R /run/mysqld
systemctl start mariadb

• Does that still fail?

[ghost]

Nope. mariaDB is running after doing that.

[MichaIng]

@FizzyAllison
Okay, that is great. But still strange why it failed during software install 🤔.

I think the install stopped then, right? In this case please re-select the chosen titles in dietpi-software to install them again. Most steps will go through faster.

[ghost]

And now redis failed:

Details:

• Date | Sun 26 May 00:34:43 BST 2019
• Bug report | N/A
• DietPi version | v6.24.1 (MichaIng/master)
• Img creator | DietPi Core Team
• Pre-image | Raspbian Lite
• SBC device | RPi B+ (armv6l) (index=1)
• Kernel version | General | Update VM images to Stretch #1219 Tue May 14 21:16:38 BST 2019
• Distro | stretch (index=4)
• Command | systemctl start redis-server
• Exit code | 1
• Software title | DietPi-Software

Steps to reproduce:

1. ...
2. ...

Expected behaviour:

• ...

Actual behaviour:

• ...

Extra details:

• ...

Additional logs:

Log file contents:
Job for redis-server.service failed because the control process exited with error code.
See "systemctl status redis-server.service" and "journalctl -xe" for details.

redis-server.service - Advanced key-value s
tore
   Loaded: loaded (/lib/systemd/system/redis-server.serv
ice; disabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since S
un 2019-05-26 00:34:35 BST; 3min 36s ago
     Docs: http://redis.io/documentation,
           man:redis-server(1)
  Process: 4246 ExecStart=/usr/bin/redis-server /etc/red
is/redis.conf (code=exited, status=1/FAILURE)
  Process: 4242 ExecStartPre=/bin/run-parts --verbose /e
tc/redis/redis-server.pre-up.d (code=exited, status=0/SU
CCESS)

May 26 00:34:34 DietPi systemd[1]: redis-server.
service: Control process exited, code=exited status=1
May 26 00:34:34 DietPi systemd[1]: Failed to sta
rt Advanced key-value store.
May 26 00:34:34 DietPi systemd[1]: redis-server.
service: Unit entered failed state.
May 26 00:34:34 DietPi systemd[1]: redis-server.
service: Failed with result 'exit-code'.
May 26 00:34:35 DietPi systemd[1]: redis-server.service:
 Service hold-off time over, scheduling restart.
May 26 00:34:35 DietPi systemd[1]: Stopped Advanced key-
value store.
May 26 00:34:35 DietPi systemd[1]: redis-server.
service: Start request repeated too quickly.
May 26 00:34:35 DietPi systemd[1]: Failed to sta
rt Advanced key-value store.
May 26 00:34:35 DietPi systemd[1]: redis-server.
service: Unit entered failed state.
May 26 00:34:35 DietPi systemd[1]: redis-server.
service: Failed with result 'exit-code'.

[MichaIng]

@FizzyAllison
cat /var/log/redis/redis-server.log

[ghost]

cat: /var/log/redis/redis-server.log: No such file or directory

[MichaIng]

@FizzyAllison
Hmm and:

systemctl restart redis-server
sleep 2
journalctl -u redis-server | tail

[ghost]

May 26 02:00:30 DietPi systemd[1]: Failed to start Advanced key-value st
ore.
May 26 02:00:30 DietPi systemd[1]: redis-server.service: Unit entered fa
iled state.
May 26 02:00:30 DietPi systemd[1]: redis-server.service: Failed with res
ult 'exit-code'.
root@DietPi:~# systemctl restart redis-server
Job for redis-server.service failed because the control process exited with error code.
See "systemctl status redis-server.service" and "journalctl -xe" for details.
root@DietPi:~# sleep 2
root@DietPi:~# journalctl -u redis-server | tail
May 26 02:20:34 DietPi systemd[1]: redis-server.service: Control process exited, code=exited status=1
May 26 02:20:34 DietPi systemd[1]: Failed to start Advanced key-value store.
May 26 02:20:34 DietPi systemd[1]: redis-server.service: Unit entered failed state.
May 26 02:20:34 DietPi systemd[1]: redis-server.service: Failed with result 'exit-code'.
May 26 02:20:34 DietPi systemd[1]: redis-server.service: Service hold-off time over, scheduling restart.
May 26 02:20:34 DietPi systemd[1]: Stopped Advanced key-value store.
May 26 02:20:34 DietPi systemd[1]: redis-server.service: Start request repeated too quickly.
May 26 02:20:34 DietPi systemd[1]: Failed to start Advanced key-value store.
May 26 02:20:34 DietPi systemd[1]: redis-server.service: Unit entered failed state.
May 26 02:20:34 DietPi systemd[1]: redis-server.service: Failed with result 'exit-code'.

[MichaIng]

@FizzyAllison
No helpful log at all, especially annoying due to the automated restart... So let's see what the bare binary call does: redis-server /etc/redis/redis.conf

[ghost]

*** FATAL CONFIG FILE ERROR ***
Reading the configuration file, at line 163
>>> 'logfile /var/log/redis/redis-server.log'
Can't open the log file: No such file or directory

[MichaIng]

@FizzyAllison
Ahh, there we have it.

mkdir -p /var/log/redis
>> /var/log/redis/redis-server.log
chown -R redis:redis /var/log/redis
systemctl restart redis-server

Strange that this was not auto-created. Always was in my case and we do no changes on top of the bare APT package install 🤔.

[ghost]

Another error, but progress is being made!

Details:

• Date | Sun 26 May 05:45:57 BST 2019
• Bug report | N/A
• DietPi version | v6.24.1 (MichaIng/master)
• Img creator | DietPi Core Team
• Pre-image | Raspbian Lite
• SBC device | RPi B+ (armv6l) (index=1)
• Kernel version | General | Update VM images to Stretch #1219 Tue May 14 21:16:38 BST 2019
• Distro | stretch (index=4)
• Command | ncc maintenance:install
• Exit code | 1
• Software title | DietPi-Software

Steps to reproduce:

1. ...
2. ...

Expected behaviour:

• ...

Actual behaviour:

• ...

Extra details:

• ...

Additional logs:

Log file contents:
Error while trying to create admin user: Failed to connect to the database: An exception occurred in driver: SQLSTATE[HY000] [1698] Access denied for user 'tmp_root'@'localhost'
 ->

[MichaIng]

@FizzyAllison
My goodness. There is obviously a deeper issue with your system if files and commands cannot be found/created that should exist or be able to be created. This database user is created with definitely correct permissions.

Please check dmesg for any red lines, e.g. I/O errors and voltage issues.
Also check again the MariaDB state:

journalctl -u mariadb
cat /var/log/mysql/error.log

[ghost]

Perhaps it’s worth starting fresh? Not like there’s anything to lose here.

[ghost]

Started fresh on a different SD card, same results. Swapped back over to the original SD card.

[ghost]

Anyways, journalctl -u mariadb log:

-- Logs begin at Sun 2019-05-26 16:12:02 BST, end at Sun 2019-05-26 17:20:04 BST
. --
May 26 17:19:56 DietPi systemd[1]: Starting MariaDB 10.1.38 database server...
May 26 17:19:58 DietPi mysqld[897]: 2019-05-26 17:19:58 3069414864 [Note] /usr/s
bin/mysqld (mysqld 10.1.38-MariaDB-0+deb9u1) starting as process 897 ...
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB
: innodb_empty_free_list_algorithm has been changed to legacy because of small b
uffer pool size. In order to use backoff, increase buffer pool at least up to 20
MB.
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB
: Using mutexes to ref count buffer pool pages
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB
: The InnoDB memory heap is disabled
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB
: Mutexes and rw_locks use GCC atomic builtins
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB
: GCC builtin __atomic_thread_fence() is used for memory barrier
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB
: Compressed tables use zlib 1.2.8
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB
: Using Linux native AIO
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB
: Using generic crc32 instructions
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB: Initializing buffer pool, size = 128.0M
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB: Completed initialization of buffer pool
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB: Highest supported file format is Barracuda.
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB: 128 rollback segment(s) are active.
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB: Waiting for purge to start
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.4
2-84.2 started; log sequence number 1616797
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 2508153648 [Note] InnoDB: Dumping buffer pool(s) not yet started
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] Plugin 'FEEDBACK' is disabled.
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] Server socket created on IP: '127.0.0.1'.
May 26 17:19:59 DietPi mysqld[897]: 2019-05-26 17:19:59 3069414864 [Note] /usr/sbin/mysqld: ready for connections.
May 26 17:19:59 DietPi mysqld[897]: Version: '10.1.38-MariaDB-0+deb9u1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Rasp
bian 9.0
May 26 17:20:00 DietPi systemd[1]: Started MariaDB 10.1.38 database server.

[ghost]

cat /var/log/mysql/error.log
cat: /var/log/mysql/error.log: No such file or directory

[MichaIng]

@FizzyAllison
So MariaDB and Redis (re)starts worked well now but you still run into the "Error while trying to create admin user" error?

[ghost]

Yep. MariaDB and Redis successfully restart, but that error you mentioned appears.

[MichaIng]

@FizzyAllison
Okay let's go manually through it:

mysql -e "grant all privileges on *.* to 'tmp_root'@'localhost' identified by 'dietpi' with grant option"
ncc(){ sudo -u www-data php /var/www/nextcloud/occ "$@"; }
ncc maintenance:install --no-interaction --database 'mysql' --database-name 'nextcloud' --database-user 'tmp_root' --database-pass "dietpi" --admin-user "admin" --admin-pass "dietpi" --data-dir "/mnt/dietpi_userdata/nextcloud_data"

• Replace "admin" with your desired Nextcloud login user name.
• Replace only the second "dietpi" in --admin-pass "dietpi" with your desired Nextcloud login password.

[ghost]

Nextcloud was successfully installed

And after all that, it appears it went smoothly.

[MichaIng]

@FizzyAllison
If not yet done, please re-run the install: dietpi-software install 114

• Since the install dir and database already exists, this will not be touched.

Still wondering why within dietpi-software so much steps failed while doing the same manually works well 🤔. Did you run dietpi-software as root user or via sudo? Should not make a difference but at least something I could try to replicate.

Ah also how much RAM space do you have: free -m

And finally it would be still good to have a look into: dmesg (red lines, errors, especially at the end of the output)

[ghost]

Nextcloud is indeed up and running, so that's solved.
But i'll provide some input that may help to hopefully fix this possible bug:
I just ran dietpi-software as the root user, as one normally does.

free -m after nextcloud install shows:

Mem:            480         102         115          21         262         306
Swap:          1566           0        1566

dmesg:

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.42+ (dom@dom-XPS-13-9370) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1219 Tue May 14 21:16:38 BST 2019
[    0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi Model B Plus Rev 1.2
[    0.000000] Memory policy: Data cache writeback
[    0.000000] cma: Reserved 8 MiB at 0x1e400000
[    0.000000] On node 0 totalpages: 126976
[    0.000000]   Normal zone: 1116 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 126976 pages, LIFO batch:31
[    0.000000] random: get_random_bytes called from start_kernel+0x8c/0x49c with crng_init=0
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 125860
[    0.000000] Kernel command line: coherent_pool=1M bcm2708_fb.fbwidth=720 bcm2708_fb.fbheight=480 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x1fa00000 vc_mem.mem_size=0x20000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty1 root=PARTUUID=b8ef7a27-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Memory: 483212K/507904K available (6932K kernel code, 633K rwdata, 2068K rodata, 456K init, 797K bss, 16500K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                   vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                   fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                   vmalloc : 0xdf800000 - 0xff800000   ( 512 MB)
                   lowmem  : 0xc0000000 - 0xdf000000   ( 496 MB)
                   modules : 0xbf000000 - 0xc0000000   (  16 MB)
                     .text : 0x(ptrval) - 0x(ptrval)   (6934 kB)
                     .init : 0x(ptrval) - 0x(ptrval)   ( 456 kB)
                     .data : 0x(ptrval) - 0x(ptrval)   ( 634 kB)
                      .bss : 0x(ptrval) - 0x(ptrval)   ( 798 kB)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] ftrace: allocating 25044 entries in 74 pages
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000029] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000084] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000192] bcm2835: system timer (irq = 27)
[    0.000786] Console: colour dummy device 80x30
[    0.001417] console [tty1] enabled
[    0.001499] Calibrating delay loop... 697.95 BogoMIPS (lpj=3489792)
[    0.060372] pid_max: default: 32768 minimum: 301
[    0.060972] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.061031] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.062515] CPU: Testing write buffer coherency: ok
[    0.063899] Setting up static identity map for 0x8200 - 0x8238
[    0.065364] devtmpfs: initialized
[    0.076199] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
[    0.076681] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.076758] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.078138] pinctrl core: initialized pinctrl subsystem
[    0.079749] NET: Registered protocol family 16
[    0.083035] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.090194] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
[    0.090271] hw-breakpoint: maximum watchpoint size is 4 bytes.
[    0.090541] Serial: AMBA PL011 UART driver
[    0.094148] bcm2835-mbox 2000b880.mailbox: mailbox enabled
[    0.136513] bcm2835-dma 20007000.dma: DMA legacy API manager at (ptrval), dmachans=0x1
[    0.139088] SCSI subsystem initialized
[    0.139417] usbcore: registered new interface driver usbfs
[    0.139562] usbcore: registered new interface driver hub
[    0.139825] usbcore: registered new device driver usb
[    0.150891] raspberrypi-firmware soc:firmware: Attached to firmware from 2019-03-27 15:46, variant start_cd
[    0.160915] raspberrypi-firmware soc:firmware: Firmware hash is 2e98b31d18547962e564bdf88e57b3df7085c29b
[    0.173286] clocksource: Switched to clocksource timer
[    0.274509] VFS: Disk quotas dquot_6.6.0
[    0.274697] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.275063] FS-Cache: Loaded
[    0.275459] CacheFiles: Loaded
[    0.294320] NET: Registered protocol family 2
[    0.295723] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes)
[    0.295848] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[    0.295960] TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
[    0.296079] TCP: Hash tables configured (established 4096 bind 4096)
[    0.296276] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.296340] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.296787] NET: Registered protocol family 1
[    0.297961] RPC: Registered named UNIX socket transport module.
[    0.298027] RPC: Registered udp transport module.
[    0.298058] RPC: Registered tcp transport module.
[    0.298083] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.300204] hw perfevents: no irqs for PMU, sampling events not supported
[    0.300330] hw perfevents: enabled with armv6_1176 PMU driver, 3 counters available
[    0.304462] Initialise system trusted keyrings
[    0.304919] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[    0.319726] FS-Cache: Netfs 'nfs' registered for caching
[    0.321100] NFS: Registering the id_resolver key type
[    0.321203] Key type id_resolver registered
[    0.321237] Key type id_legacy registered
[    0.321289] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.327074] Key type asymmetric registered
[    0.327143] Asymmetric key parser 'x509' registered
[    0.327281] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[    0.327805] io scheduler noop registered
[    0.327862] io scheduler deadline registered (default)
[    0.328534] io scheduler cfq registered
[    0.328589] io scheduler mq-deadline registered (default)
[    0.328623] io scheduler kyber registered
[    0.331813] BCM2708FB: allocated DMA memory 0x5e500000
[    0.331928] BCM2708FB: allocated DMA channel 0
[    0.338209] Console: switching to colour frame buffer device 90x30
[    0.347254] bcm2835-rng 20104000.rng: hwrng registered
[    0.349550] vc-mem: phys_addr:0x00000000 mem_base=0x1fa00000 mem_size:0x20000000(512 MiB)
[    0.354876] vc-sm: Videocore shared memory driver
[    0.357658] gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
[    0.380384] brd: module loaded
[    0.395937] loop: module loaded
[    0.398006] Loading iSCSI transport class v2.0-870.
[    0.400930] usbcore: registered new interface driver smsc95xx
[    0.403001] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.433190] dwc_otg 20980000.usb: base=(ptrval)
[    0.635735] Core Release: 2.80a
[    0.637757] Setting default values for core params
[    0.639724] Finished setting default values for core params
[    0.842078] Using Buffer DMA mode
[    0.844114] Periodic Transfer Interrupt Enhancement - disabled
[    0.846041] Multiprocessor Interrupt Enhancement - disabled
[    0.847949] OTG VER PARAM: 0, OTG VER FLAG: 0
[    0.849965] Dedicated Tx FIFOs mode
[    0.852822] WARN::dwc_otg_hcd_init:1045: FIQ DMA bounce buffers: virt = de514000 dma = 0x5e514000 len=9024
[    0.857030] FIQ FSM acceleration enabled for :
               Non-periodic Split Transactions
               Periodic Split Transactions
               High-Speed Isochronous Endpoints
               Interrupt/Control Split Transaction hack enabled
[    0.867060] dwc_otg: Microframe scheduler enabled
[    0.867319] WARN::hcd_init_fiq:457: FIQ on core 0
[    0.869307] WARN::hcd_init_fiq:458: FIQ ASM at c04f48a0 length 36
[    0.871258] WARN::hcd_init_fiq:484: MPHI regs_base at f0006000
[    0.873238] dwc_otg 20980000.usb: DWC OTG Controller
[    0.875239] dwc_otg 20980000.usb: new USB bus registered, assigned bus number 1
[    0.877291] dwc_otg 20980000.usb: irq 56, io mem 0x00000000
[    0.879246] Init: Port Power? op_state=1
[    0.881108] Init: Power Port (0)
[    0.883449] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    0.887269] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.889301] usb usb1: Product: DWC OTG Controller
[    0.891302] usb usb1: Manufacturer: Linux 4.19.42+ dwc_otg_hcd
[    0.893369] usb usb1: SerialNumber: 20980000.usb
[    0.896539] hub 1-0:1.0: USB hub found
[    0.898669] hub 1-0:1.0: 1 port detected
[    0.901699] dwc_otg: FIQ enabled
[    0.901712] dwc_otg: NAK holdoff enabled
[    0.901719] dwc_otg: FIQ split-transaction FSM enabled
[    0.901738] Module dwc_common_port init
[    0.902298] usbcore: registered new interface driver usb-storage
[    0.904971] mousedev: PS/2 mouse device common for all mice
[    0.908401] bcm2835-wdt 20100000.watchdog: Broadcom BCM2835 watchdog timer
[    0.910975] bcm2835-cpufreq: min=700000 max=900000
[    0.913765] sdhci: Secure Digital Host Controller Interface driver
[    0.915781] sdhci: Copyright(c) Pierre Ossman
[    0.918397] sdhost-bcm2835 20202000.mmc: could not get clk, deferring probe
[    0.920707] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.923749] ledtrig-cpu: registered to indicate activity on CPUs
[    0.926061] hidraw: raw HID events driver (C) Jiri Kosina
[    0.928405] usbcore: registered new interface driver usbhid
[    0.930503] usbhid: USB HID core driver
[    0.933733] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0
[    0.938018] [vc_sm_connected_init]: start
[    0.942247] vc_vchi_sm_init: failed to open VCHI service (-1)
[    0.942269] [vc_sm_connected_init]: failed to initialize shared memory service
[    0.946784] [vc_sm_connected_init]: end - returning -1
[    0.950749] Initializing XFRM netlink socket
[    0.952972] NET: Registered protocol family 17
[    0.955248] Key type dns_resolver registered
[    0.959061] registered taskstats version 1
[    0.961115] Loading compiled-in X.509 certificates
[    0.975850] sdhost: log_buf @ (ptrval) (5e513000)
[    1.025400] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    1.029108] of_cfs_init
[    1.031327] of_cfs_init: OK
[    1.054671] Waiting for root device PARTUUID=b8ef7a27-02...
[    1.067081] random: fast init done
[    1.113775] Indeed it is in host mode hprt0 = 00021501
[    1.187011] mmc0: host does not support reading read-only switch, assuming write-enable
[    1.192533] mmc0: new high speed SDHC card at address aaaa
[    1.196628] mmcblk0: mmc0:aaaa SC32G 29.7 GiB
[    1.204770]  mmcblk0: p1 p2
[    1.253915] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    1.258107] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.273077] devtmpfs: mounted
[    1.280292] Freeing unused kernel memory: 456K
[    1.282446] This architecture does not have kernel memory protection.
[    1.284621] Run /sbin/init as init process
[    1.323451] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    1.326203] Indeed it is in host mode hprt0 = 00001101
[    1.564319] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00
[    1.568702] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.573571] hub 1-1:1.0: USB hub found
[    1.577823] hub 1-1:1.0: 5 ports detected
[    1.903419] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    1.925961] systemd[1]: System time before build time, advancing clock.
[    2.033880] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00
[    2.038894] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.047889] smsc95xx v1.0.6
[    2.125580] NET: Registered protocol family 10
[    2.130246] Segment Routing with IPv6
[    2.164281] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-20980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:69:6d:b3
[    2.183526] random: systemd: uninitialized urandom read (16 bytes read)
[    2.196697] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[    2.205401] systemd[1]: Detected architecture arm.
[    2.223615] systemd[1]: Set hostname to <DietPi>.
[    2.304210] random: systemd: uninitialized urandom read (16 bytes read)
[    2.531462] random: systemd-cryptse: uninitialized urandom read (16 bytes read)
[    3.213870] systemd[1]: systemd-logind.service: Cannot add dependency job, ignoring: Unit systemd-logind.service is masked.
[    3.219416] systemd[1]: getty-static.service: Cannot add dependency job, ignoring: Unit getty-static.service is masked.
[    3.234909] systemd[1]: Created slice System Slice.
[    3.242660] systemd[1]: Listening on Journal Socket (/dev/log).
[    3.249691] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    3.256799] systemd[1]: Listening on Journal Socket.
[    3.272847] systemd[1]: Starting Restore / save the current clock...
[    6.513432] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    8.166511] systemd-journald[79]: Received request to flush runtime journal from PID 1
[    8.642384] Adding 1604604k swap on /var/swap.  Priority:-2 extents:8 across:1809404k SSFS
[    9.369064] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    9.371437] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    9.371459] [vc_sm_connected_init]: start
[    9.403739] vc_sm_cma_vchi_init: failed to open VCHI service (-1)
[    9.403765] [vc_sm_connected_init]: failed to initialize shared memory service
[    9.403773] [vc_sm_connected_init]: failed, ret -1
[    9.406709] media: Linux media interface: v0.10
[    9.563749] videodev: Linux video capture interface: v2.00
[    9.635521] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    9.680934] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    9.712737] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    9.718455] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
[    9.734587] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
[   18.410412] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[   19.862476] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1
[   30.541193] random: crng init done
[   30.541216] random: 7 urandom warning(s) missed due to ratelimiting

[ghost]

And currently re-running the install as you suggested.

[MichaIng]

[ 30.541193] random: crng init done
[ 30.541216] random: 7 urandom warning(s) missed due to ratelimiting

Okay it "might" be an entropy pool issue. We observed this on some more systems. It is a known issue to Debian and systemd but there has not yet been done some progress to solve this.

Does boot and/or service restarts that very long, or do some services not start up at boot as expected?

[ghost]

Everything boots up normally and doesn't appear to be very long.

[ghost]

dietpi-software install 114 :

Mode: Installation completed

[MichaIng]

@FizzyAllison
Okay good. I face the same random errors on boot (on my RPi) and do not run into further issues as well. But other users do, so worth to ask.

Great that finally the install went through.

I mark this issue as closed then. When you face a similar issue again during another software install, please open another issue and remind me (by placing a link) about this one. So we need to have a closer look why the issues occur. One idea I have is that we might need to wait 1-2 seconds after service restarts to assure they have fully finished on slower devices. The systemd units should include this, if required, but sometimes they don't.
So e.g. even that systemctl restart mariadb has finished to go on with the next command in line, the MariaDB server has actually not yet fully started up, thus database access fails. Same could be true after stopping services, that not yet all stop tasks have fully finished before we attempt restart. Just an idea since you use relatively slow RPi1.