Koozali.org: home of the SME Server

Workstation Restore. How long? Hangs up?

Offline fastxl

  • *
  • 32
  • +0/-0
Workstation Restore. How long? Hangs up?
« on: January 15, 2020, 07:57:22 PM »
SO I am trying to migrate from 8.2 to 9.2. I did a Workstation restore from my backup. It started a long list of files that it was restoring. It gets to the end and says "Clearing Memory" and nothing happens. Been over 4 hours. When I try to refresh the web page it takes me to the login screen. When I try to log in with admin, I get wrong username or password. I can still log in via SSH with root. Just can't log in with admin.

This is a fresh install of 9.2, installed whatever updates were required, then did a restore from workstation backup (after configuring it to point to my backup files on a Windows share).

I never see a reboot to complete. How long should this take. Log files anywhere to see progress? Messages doesn't seem to show anything.

Offline Jean-Philippe Pialasse

  • *
  • 2,746
  • +11/-0
  • aka Unnilennium
    • http://smeserver.pialasse.com
Re: Workstation Restore. How long? Hangs up?
« Reply #1 on: January 15, 2020, 11:36:14 PM »
Same one i pointed in your previous post

tail -f -n 100 /var/log/messages

Offline fastxl

  • *
  • 32
  • +0/-0
Re: Workstation Restore. How long? Hangs up?
« Reply #2 on: January 16, 2020, 02:02:23 PM »
/var/log/messages was the first place I looked and this is the result I get when I "tail" it
Code: [Select]
tail: cannot open `/var/log/messages' for reading: No such file or directoryWhen I
Code: [Select]
ls -l /var/log/messages I get this
Code: [Select]
messages -> /var/log/messages.20200115080553No file named
Code: [Select]
messages.20200115080553 in the /var/log. When I
Code: [Select]
ls -l /var/log/messages* I get
Code: [Select]
lrwxrwxrwx 1 root admin     32 Jan 15 08:05 messages -> /var/log/messages.20200115080553
-rw------- 1 root root   47831 Jan 15 06:34 messages.20200115063411
-rw------- 1 root root  577955 Jan 15 06:52 messages.20200115063412
-rw------- 1 root root  174011 Jan 16 06:11 messages.20200115065249
When I (tail the lastest log file)
Code: [Select]
tail -f -n 100 /var/log/messages.20200115065249 I see things happening. I see that it tried to do a workstation backup at 9pm last night because that is how I had it configured. Here is the results of the tail
Code: [Select]
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $uid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: Use of uninitialized value $gid in chown at /usr/share/perl5/vendor_perl/esmith/util.pm line 102.
Jan 15 08:06:24 sme92 esmith::event[19593]: S20user-create-profiledir=action|Event|post-upgrade|Action|S20user-create-profiledir|Start|1579097184 659895|End|1579097184 820999|Elapsed|0.161104
Jan 15 08:06:24 sme92 esmith::event[19593]: Running event handler: /etc/e-smith/events/post-upgrade/S25count-active-user-accounts
Jan 15 08:06:24 sme92 esmith::event[19593]: S25count-active-user-accounts=action|Event|post-upgrade|Action|S25count-active-user-accounts|Start|1579097184 821331|End|1579097184 928304|Elapsed|0.106973
Jan 15 08:06:24 sme92 esmith::event[19593]: Running event handler: /etc/e-smith/events/post-upgrade/S30conf-modules
Jan 15 08:06:34 sme92 esmith::event[19593]: S30conf-modules=action|Event|post-upgrade|Action|S30conf-modules|Start|1579097184 928838|End|1579097194 132467|Elapsed|9.203629
Jan 15 08:06:34 sme92 esmith::event[19593]: Running event handler: /etc/e-smith/events/post-upgrade/S50create-mnt-floppy
Jan 15 08:06:34 sme92 esmith::event[19593]: S50create-mnt-floppy=action|Event|post-upgrade|Action|S50create-mnt-floppy|Start|1579097194 133113|End|1579097194 192541|Elapsed|0.059428
Jan 15 08:06:34 sme92 esmith::event[19593]: Running event handler: /etc/e-smith/events/post-upgrade/S90copy-anaconda-logs
Jan 15 08:06:34 sme92 esmith::event[19593]: S90copy-anaconda-logs=action|Event|post-upgrade|Action|S90copy-anaconda-logs|Start|1579097194 193000|End|1579097194 245965|Elapsed|0.052965
Jan 15 08:06:34 sme92 esmith::event[19593]: Running event handler: /etc/e-smith/events/post-upgrade/S90testing-conf
Jan 15 08:06:34 sme92 esmith::event[19593]: S90testing-conf=action|Event|post-upgrade|Action|S90testing-conf|Start|1579097194 246448|End|1579097194 341647|Elapsed|0.095199
Jan 15 21:00:01 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: OLD 1579143601=(undefined)
Jan 15 21:00:01 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: NEW 1579143601=backup_record
Jan 15 21:00:01 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: OLD 1579143601=backup_record
Jan 15 21:00:01 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: NEW 1579143601=backup_record|StartEpochTime|1579143601
Jan 15 21:00:01 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: OLD 1579143601=backup_record|StartEpochTime|1579143601
Jan 15 21:00:01 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: NEW 1579143601=backup_record|BackupType|workstation|StartEpochTime|1579143601
Jan 15 21:00:01 sme92 esmith::event[19891]: Processing event: pre-backup
Jan 15 21:00:01 sme92 esmith::event[19891]: Running event handler: /etc/e-smith/events/actions/generic_template_expand
Jan 15 21:00:01 sme92 esmith::event[19891]: expanding /etc/dar/DailyBackup.dcf
Jan 15 21:00:02 sme92 esmith::event[19891]: generic_template_expand=action|Event|pre-backup|Action|generic_template_expand|Start|1579143601 838550|End|1579143602 65814|Elapsed|0.227264
Jan 15 21:00:02 sme92 esmith::event[19891]: Running event handler: /etc/e-smith/events/pre-backup/S10mysql-delete-dumped-tables
Jan 15 21:00:02 sme92 esmith::event[19891]: S10mysql-delete-dumped-tables=action|Event|pre-backup|Action|S10mysql-delete-dumped-tables|Start|1579143602 66231|End|1579143602 123157|Elapsed|0.056926
Jan 15 21:00:02 sme92 esmith::event[19891]: Running event handler: /etc/e-smith/events/pre-backup/S20mysql-dump-tables
Jan 15 21:00:02 sme92 esmith::event[19891]: ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)
Jan 15 21:00:02 sme92 esmith::event[19891]: S20mysql-dump-tables=action|Event|pre-backup|Action|S20mysql-dump-tables|Start|1579143602 123963|End|1579143602 366517|Elapsed|0.242554
Jan 15 21:00:02 sme92 esmith::event[19891]: Running event handler: /etc/e-smith/events/pre-backup/S30ldap-dump
Jan 15 21:00:02 sme92 esmith::event[19891]: 5e1fd1b2 bdb_db_open: warning - no DB_CONFIG file found in directory /var/lib/ldap: (2).
Jan 15 21:00:02 sme92 esmith::event[19891]: Expect poor performance for suffix "dc=mmt,dc=muellermachine,dc=com".
Jan 15 21:00:02 sme92 esmith::event[19891]: 5e1fd1b2 bdb_db_open: database "dc=mmt,dc=muellermachine,dc=com": db_open(/var/lib/ldap/id2entry.bdb) failed: No such file or directory (2).
Jan 15 21:00:02 sme92 esmith::event[19891]: 5e1fd1b2 backend_startup_one (type=bdb, suffix="dc=mmt,dc=muellermachine,dc=com"): bi_db_open failed! (2)
Jan 15 21:00:02 sme92 esmith::event[19891]: slap_startup failed
Jan 15 21:00:02 sme92 esmith::event[19891]: S30ldap-dump=action|Event|pre-backup|Action|S30ldap-dump|Start|1579143602 367124|End|1579143602 829638|Elapsed|0.462514|Status|256
Jan 15 21:00:02 sme92 esmith::event[19891]: Running event handler: /etc/e-smith/events/pre-backup/S50rewind-tape
Jan 15 21:00:02 sme92 esmith::event[19891]: S50rewind-tape=action|Event|pre-backup|Action|S50rewind-tape|Start|1579143602 829825|End|1579143602 876133|Elapsed|0.046308
Jan 15 21:00:02 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: OLD 1579143601=backup_record|BackupType|workstation|StartEpochTime|1579143601
Jan 15 21:00:02 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: NEW 1579143601=backup_record|BackupType|workstation|EndEpochTime|1579143602|StartEpochTime|1579143601
Jan 15 21:00:02 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: OLD 1579143601=backup_record|BackupType|workstation|EndEpochTime|1579143602|StartEpochTime|1579143601
Jan 15 21:00:02 sme92 /sbin/e-smith/do_backupwk[19890]: /home/e-smith/db/backups: NEW 1579143601=backup_record|BackupType|workstation|EndEpochTime|1579143602|Result|pre-backup:256|StartEpochTime|1579143601
Jan 16 03:06:02 sme92 logrotate: ALERT exited abnormally with [1]
Is there anything in particular I should be looking for? Anyway to check the status of the restore?

Offline janet

  • ****
  • 4,812
  • +0/-0
Re: Workstation Restore. How long? Hangs up?
« Reply #3 on: January 16, 2020, 02:25:47 PM »
fastxl

Quote
I did a Workstation restore from my backup. It started a long list of files that it was restoring. It gets to the end and says "Clearing Memory" and nothing happens. Been over 4 hours.........I never see a reboot to complete. How long should this take.

You MUST wait until you see a message Restore complete or similar. It seems you Refreshed the page too soon before the restore had completed.

Yes I know 4 hrs is a long time, & it may seem as if nothing is happening & perhaps even seem like the system has frozen, BUT it can take a very long time, even longer than 4 hrs, you just have to wait until you get the Restore complete message !

Try again, & this time be VERY PATIENT.
Please search before asking, an answer may already exist.
The Search & other links to useful information are at top of Forum.

Offline Jean-Philippe Pialasse

  • *
  • 2,746
  • +11/-0
  • aka Unnilennium
    • http://smeserver.pialasse.com
Re: Workstation Restore. How long? Hangs up?
« Reply #4 on: January 16, 2020, 06:04:42 PM »
If refreshing the page lead to the login, it could be the timeout has been hit because the procedure did not refresh the display frequently enough.

There has been a change in the last years to introduce a timeout. I do not say it is a bug and this is happening for real but worth investigating.