long time waiting for virtual terminal initialize

Asked by chchang

I'm trying to build a customize ubuntu 20.04 ISO.
But I found that each time I entered virtual Terminal, I had to wait for a very long time (at least 10 mins and more)
I paid particular attention to the use of system resources during this period, and there were no particularly significant exceptions.
cpu usage/memory usage were both very low.

is this a "problem" ? or it's just nomal ?

Question information

Language:
English Edit question
Status:
Expired
For:
Cubic Edit question
Assignee:
No assignee Edit question
Last query:
Last reply:
Revision history for this message
Cubic PPA (cubic-wizard) said :
#1

This is not normal; it should be almost instantaneous.

What kind of machine (specs) are you running Cubic in?
Is it a virtual machine? If so, what are the specs of the host machine, and what are the specs of the virtual machine?
What OS and version is the host machine using?

Also, please do the following experiment, if you get a chance:
Once you are in the virtual terminal, type "exit" and press enter.
Cubic should restart the virtual environment for you, and it should be instantaneous.
Does it take 10 minutes in this scenario?

Revision history for this message
Cubic PPA (cubic-wizard) said :
#2

Also, please let me know what is the version of Cubic you are using?

Revision history for this message
chchang (mc-z) said :
#3

not a VM.

here are the environments.

Cubic version 2020.10.34

OS: ubuntu 20.04 x64
CPU: core i7-3770
RAM: 24GB
HDD: Adata SU650 480G

>>Once you are in the virtual terminal, type "exit" and press enter.
>>Cubic should restart the virtual environment for you, and it should be instantaneous.

it is instantaneous. no need to wait.

and what else you need ?

Revision history for this message
Cubic PPA (cubic-wizard) said :
#4

Thanks for this info.

Your machine specs are more than enough, and you are using the latest version of Cubic.

The process for (re)starting the virtual terminal when you type "exit" is essentially the same as when you first enter the terminal from the previous page in Cubic(either the Project page or the Extract page).

If you could supply the following info, it would help...

[1]
Please further elaborate on the delay you are experiencing. Exactly when do you see it?...

(a) Does this delay happen while on the Project* page after you've clicked the Customize button (for an existing project)?
    ...or...
(b) Does this delay happen while on the Extract* page, before the Terminal page is automatically displayed?
    ...or...
(c) Does this delay happen once you see the Terminal page, while you are waiting for the message "You have entered the virtual environment" to appear in the terminal?

* Note:
The Project page is the page with all the fields for the Original ISO and the Custom ISO.
The Extract page is the page progress for showing "Extracting linux file system" and "Copying important files". This page usually shows up for new projects only.
Either of these pages may immediately precede the Terminal page.

[2]
Open a terminal on your host computer.
Run cubic from the command-line, by typing "cubic" and pressing the Enter key.

Navigate to Cubic's Terminal page by clicking Next/Generate in Cubic.

Watch the output on the host terminal.
Make a not of the LAST message that is displayed, ~before~ you end up having to wait.

Once you see the message "You have entered the virtual environment" in Cubic, please copy the output from your host computer and paste it here.

Be sure to share the "LAST message" you noted above. (This will help me figure out where in the code this delay starts).

Revision history for this message
Cubic PPA (cubic-wizard) said :
#5

Simultaneously with comment #4, let's also look at your host system and see if there are any errors related to services used by Cubic.

Immediately after launching Cubic, open a 2nd terminal on your host machine.

Type "journalctl -f" and press Enter.

This will output system information. The nice thing is we will get some time stamps to look at.

Once you see the message "You have entered the virtual environment" in Cubic, press <CTRL><C> in the 2nd terminal to stop this output.

Then please copy the output and paste it here.

Revision history for this message
chchang (mc-z) said :
#6

Please further elaborate on the delay you are experiencing. Exactly when do you see it?...

(c) Does this delay happen once you see the Terminal page, while you are waiting for the message "You have entered the virtual environment" to appear in the terminal

cubic console messages
https://paste.laravel.io/f5d3cd0f-4ac2-40c8-a7ce-c22d3ab2604b

journalctl messgaes
https://paste.laravel.io/02bb7b2d-d8d4-46ea-add1-f52d60fc1353

Revision history for this message
Cubic PPA (cubic-wizard) said :
#7

[1] cubic console messages

Do you remember which line was the output in the "cubic console message" when the delay started.
(What I mean is, the console messages must have stopped for some time, and then restarted once the virtual terminal became available).

[2] journalctl messgaes

Take a look at my journalctl log when I run Cubic...

    Oct 21 13:17:31 TEST_PC systemd[2715]: Started VTE child process 10819 launched by cubic.py process 10771.
    Oct 21 13:17:31 TEST_PC pkexec[10819]: pam_unix(polkit-1:session): session opened for user root by (uid=1000)
    Oct 21 13:17:31 TEST_PC pkexec[10819]: test_user: Executing command [USER=root] [TTY=/dev/pts/2] [CWD=/usr/share/cubic] [COMMAND=/usr/share/cubic/commands/start-virtual-environment cubic /mnt/ram/Ubuntu/custom-root]
    Oct 21 13:17:31 TEST_PC systemd-machined[10544]: New machine cubic.
    Oct 21 13:17:31 TEST_PC systemd[1]: Started Container cubic.

Notice how there is an "Executing command" message at time stamp 13:17:31, and a subsequent "Started Container cubic" message at time stamp 13:17:31. You can see this is really instantaneous by looking at the time stamps.

In your output, I ~only~ see the following...

    Oct 21 10:33:43 dc.abc.com systemd[4241]: Started VTE child process 577826 launched by cubic.py process 577747.
    Oct 21 10:33:43 dc.abc.com pkexec[577826]: pam_unix(polkit-1:session): session opened for user root by (uid=1001)

This matches the first two lines in my example log above. However, there are *no* subsequent references to cubic in your journalctl log. There should be a "Executing command" line some time after the above two lines. Is there a portion of this log missing?

Revision history for this message
Cubic PPA (cubic-wizard) said :
#8

Chchang,

One more question...

Are you experiencing any other delays in Cubic?
For example, when first launching Cubic, mounting the original ISO, extracting the Linux file system (for a new project), or clicking Back/Next buttons on other pages.

There shouldn't be any significant delays; Cubic is pretty responsive.

(I wondering if there is a general issue that just happens to be more obvious when entering the Terminal page).

Revision history for this message
LeeMinWoo (misari) said :
#9

I have same problem too!

My machine is
- CPU: i7-6700HQ 8 core
- RAM: 8GB
- OS: Ubuntu 20.04.1 amd64
- kernel: 5.4.0-52-generic #57-Ubuntu SMP Thu Oct 15 10:57:00 UTC 2020 x86_64

I entered virtual Terminal after waiting about ten minutes.

When i waiting for enter the virtual terminal, In the another terminal i excuted 'ps -ef | grep systemd-nspawn'
and i killed the process. so i could entered the virtual terminal instantly. at that time, i confirmed that another systemd-nspawn was executed.

Revision history for this message
chchang (mc-z) said :
#11

>>Are you experiencing any other delays in Cubic?
>>For example, when first launching Cubic, mounting the original ISO, extracting the Linux file system (for a new project), or clicking >>Back/Next buttons on other pages.

no , all the other pages responded quickly

Revision history for this message
chchang (mc-z) said :
#12

Do you remember which line was the output in the "cubic console message" when the delay started.

here

  Watch virtual environment
  • System bus id.......................... 139817203716352
  • Subscribe to virtual environment
    entered signals with subscription id... 139817203056384
  • The pseudo terminal process id is...... 608162
  • Subscribe to virtual environment
    exited events for process id........... 608162

and journal logs shows no following execute commands

Oct 22 10:01:05 dc.abc.com systemd[4241]: Started Tracker metadata database store and lookup manager.
Oct 22 10:01:07 dc.abc.com systemd[4241]: Started VTE child process 608162 launched by cubic.py process 608105.
Oct 22 10:01:07 dc.abc.com pkexec[608162]: pam_unix(polkit-1:session): session opened for user root by (uid=1001)

Revision history for this message
chchang (mc-z) said :
#13

LeeMinWoo

>>When i waiting for enter the virtual terminal, In the another terminal i excuted 'ps -ef | grep systemd-nspawn'
>>and i killed the process. so i could entered the virtual terminal instantly. at that time, i confirmed that another systemd-nspawn >>was executed.

and all procedures still works ?

Revision history for this message
LeeMinWoo (misari) said :
#14

chchang (mc-z)
All is good after thai i forcely killed systemd-nspawn process.

Revision history for this message
chchang (mc-z) said :
#15

LeeMinWoo

thanks , I'll try .

Cubic PPA (cubic-wizard)

I think the issue is related to ubuntu 20.04 .

I copy the cubic project folder to another host running ubuntu 18.04 then it's ok.

Revision history for this message
LeeMinWoo (misari) said :
#16

I am suspicious that cubic is not properly getting the exit code from the 'systemd-nspawn execution.

Revision history for this message
Cubic PPA (cubic-wizard) said :
#17

LeeMinWoo,

Thanks for the insight.

If you are on the Terminal page, and you type exit, Cubic will restart systemd-nspawn.
This is similar to killing systemd-nspawn; Cubic will simply restart it.

So this is a short-term work-around for you guys.

However, why is it taking so long on initial startup?

I am using 20.04 and I have not experienced this issue.

LeeMinWoo, this may be unrelated, but which OS are you customizing using Cubic? (I already know you are running Ubuntu 20.04 Deskrot version on your host machine).

Revision history for this message
Cubic PPA (cubic-wizard) said :
#18

I'd like to get a better understanding of what is in-common with your setups, since you are both experiencing this?
What kernel versions are you guys running?

LeeMinWoo,

What does the output of "journalctl -f" look like while using Cubic?

Revision history for this message
chchang (mc-z) said :
#19

chchang@dc:~$ cat /etc/os-release
NAME="Ubuntu"
VERSION="20.04.1 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.1 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal

chchang@dc:~$ uname -r
5.4.0-52-generic
chchang@dc:~$

Revision history for this message
Cubic PPA (cubic-wizard) said :
#20

Humm.

I have the exact same setup, and it takes less than 10 milliseconds to enter the Terminal.

$ cat /etc/os-release
NAME="Ubuntu"
VERSION="20.04.1 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.1 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal

$ uname -r
5.4.0-52-generic

Revision history for this message
Cubic PPA (cubic-wizard) said :
#21

LeeMinWoo,

When you get a chance, please share the output of cat /etc/os-release, uname -r, and journalctl -f

Are you both customizing Ubuntu Server ?

Revision history for this message
LeeMinWoo (misari) said :
#22

$ cat /etc/os-release
NAME="Ubuntu"
VERSION="20.04.1 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.1 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal

$ uname -r
5.4.0-52-generic

below message is when i do not get virtual terminal prompt yet.

$ journalctl -f
10월 23 11:19:41 minwoo-notebook pkexec[101105]: minwoo: Executing command [USER=root] [TTY=/dev/pts/3] [CWD=/usr/share/cubic] [COMMAND=/usr/share/cubic/commands/mount /opt/custom-ubuntu-iso/source-disk /opt/custom-ubuntu-iso/ubuntu-20.04.1-2020.10.21-desktop-amd64.iso]
10월 23 11:19:41 minwoo-notebook kernel: ISO 9660 Extensions: Microsoft Joliet Level 3
10월 23 11:19:41 minwoo-notebook kernel: ISO 9660 Extensions: Microsoft Joliet Level 3
10월 23 11:19:41 minwoo-notebook kernel: ISO 9660 Extensions: RRIP_1991A
10월 23 11:19:43 minwoo-notebook systemd[2149]: Started VTE child process 101129 launched by cubic.py process 101008.
10월 23 11:19:43 minwoo-notebook pkexec[101129]: pam_unix(polkit-1:session): session opened for user root by (uid=1000)
10월 23 11:19:43 minwoo-notebook pkexec[101129]: minwoo: Executing command [USER=root] [TTY=/dev/pts/3] [CWD=/usr/share/cubic] [COMMAND=/usr/share/cubic/commands/start-virtual-environment cubic /opt/custom-ubuntu-iso/custom-root]
10월 23 11:19:43 minwoo-notebook dbus-daemon[1028]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service' requested by ':1.321' (uid=0 pid=101132 comm="systemd-nspawn --quiet --notify-ready=yes --regist" label="unconfined")
10월 23 11:19:43 minwoo-notebook systemd[1]: Created slice Virtual Machine and Container Slice.
10월 23 11:19:43 minwoo-notebook systemd[1]: Condition check resulted in Virtual Machine and Container Storage (Compatibility) being skipped.
10월 23 11:19:44 minwoo-notebook systemd[1]: Starting Virtual Machine and Container Registration Service...
10월 23 11:19:44 minwoo-notebook dbus-daemon[1028]: [system] Successfully activated service 'org.freedesktop.machine1'
10월 23 11:19:44 minwoo-notebook systemd[1]: Started Virtual Machine and Container Registration Service.
10월 23 11:19:44 minwoo-notebook systemd-machined[101136]: New machine cubic.
10월 23 11:19:44 minwoo-notebook systemd[1]: Started Container cubic.
10월 23 11:20:01 minwoo-notebook systemd[1]: systemd-hostnamed.service: Succeeded.

Revision history for this message
Cubic PPA (cubic-wizard) said :
#23

Thanks.

All three of us have the same system setup.

Also, your journalctl log looks just like mine.
We can see it only takes one second to start the Terminal.

However, you do not see the "success" message in Cubic.
This is a good clue.

10월 23 11:19:43 minwoo-notebook systemd[2149]: Started VTE child process 101129 launched by cubic.py process 101008.
10월 23 11:19:43 minwoo-notebook pkexec[101129]: pam_unix(polkit-1:session): session opened for user root by (uid=1000)
10월 23 11:19:43 minwoo-notebook pkexec[101129]: minwoo: Executing command [USER=root] [TTY=/dev/pts/3] [CWD=/usr/share/cubic] [COMMAND=/usr/share/cubic/commands/start-virtual-environment cubic /opt/custom-ubuntu-iso/custom-root]
10월 23 11:19:44 minwoo-notebook systemd-machined[101136]: New machine cubic.
10월 23 11:19:44 minwoo-notebook systemd[1]: Started Container cubic.

Revision history for this message
Cubic PPA (cubic-wizard) said :
#24

While you are waiting (for up to 10 minutes) do you guys see the following messages?...

In the Terminal:

    Green text, "You have entered the virtual environment"

Above the Terminal,

    A check-mark with the text, "You are in the virtual environment"

Revision history for this message
chchang (mc-z) said :
#25

no and no.

Revision history for this message
Cubic PPA (cubic-wizard) said :
#26

OK.

Cubic listens for a D-Bus message from systemd to notify it that the container successfully started.

It may be that the signal is never sent, or it is delayed on your systems.
(Delayed seems more likely, since you had to wait a long time).

If you can think of anything special/different/unique about your system setups, please share it.

I'll keep looking into this to see if I can make the process more robust.

In the mean time, killing the systemd-nspawn seems to work for you, as a work-around.

You can also use the following command from a terminal window on your host machine.

    $ sudo machinectl terminate cubic

Revision history for this message
LeeMinWoo (misari) said :
#27

Cubic PPA (cubic-wizard)
Thank you for your kindness response.

'$ sudo machinectl terminate cubic' is nice solution in this situation.

Revision history for this message
Launchpad Janitor (janitor) said :
#28

This question was expired because it remained in the 'Open' state without activity for the last 15 days.