Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

octoprint --daemon is broken in 1.3.0 #1641

Closed
malnvenshorn opened this issue Dec 10, 2016 · 17 comments

Comments

Projects
None yet
5 participants
@malnvenshorn
Copy link
Contributor

commented Dec 10, 2016

What were you doing?

Trying to start OctoPrint after updating to version 1.3.0.

What did you expect to happen?

That OctoPrint starts ;-)

What happened instead?

OctoPrint seems to be stuck in a loop. There is a recurring process which takes full CPU load for a few seconds then disappears and appears again and so on.... Restarted my RaspberryPi but OctoPrint is stuck again.

Branch & Commit or Version of OctoPrint

1.3.0

Printer model & used firmware incl. version


Browser and Version of Browser, Operating System running Browser


Link to octoprint.log

http://pastebin.com/FaYqBcMP

The Log ends after updating. The endless loop doesn't produce any message in the log file.

Link to contents of terminal tab or serial.log


Link to contents of Javascript console in the browser


Screenshot(s) showing the problem:


@GitIssueBot

This comment has been minimized.

Copy link
Collaborator

commented Dec 10, 2016

Hi @malnvenshorn,

It looks like there is some information missing from your bug report that will be needed in order to solve the problem. Read the Contribution Guidelines which will provide you with a template to fill out here so that your bug report is ready to be investigated (I promise I'll go away then too!).

If you did not intend to report a bug but wanted to request a feature or brain storm about some kind of development, please take special note of the title format to use as described in the Contribution Guidelines.

Please do not abuse the bug tracker as a support forum - if you have a question or otherwise need some kind of help or support refer to the Mailinglist or the G+ Community instead of here.

Also make sure you are at the right place - this is the bug tracker of the official version of OctoPrint, not the Raspberry Pi image OctoPi nor any unbundled third party OctoPrint plugins or unofficial versions. Make sure too that you have read through the Frequently Asked Questions and searched the existing tickets for your problem - try multiple search terms please.

I'm marking this one now as needing some more information. Please understand that if you do not provide that information within the next two weeks (until 2016-12-24 22:20 UTC) I'll close this ticket so it doesn't clutter the bug tracker. This is nothing personal, so please just be considerate and help the maintainers solve this problem quickly by following the guidelines linked above. Remember, the less time the devs have to spend running after information on tickets, the more time they have to actually solve problems and add awesome new features. Thank you!

Best regards,
~ Your friendly GitIssueBot

PS: I'm just an automated script, not a human being, so don't expect any replies from me :) Your ticket is read by humans too, I'm just not one of them.

@foosel

This comment has been minimized.

Copy link
Owner

commented Dec 10, 2016

If there's no logging output at all after the update, it doesn't look like the server process is even starting (logging that it is starting is pretty much the first thing it will do after basic initialisation of config and logging).

Let's see if there's some error thrown before the logging system is initialised. Please try SSHing into your Pi, then

  • sudo service octoprint stop
  • ~/oprint/bin/octoprint serve

What output does this produce?

PS: do not remove any lines not in [ and ] from the bug template or the bot will complain

@malnvenshorn

This comment has been minimized.

Copy link
Contributor Author

commented Dec 11, 2016

Found the issue "Daemon operation via "octoprint --daemon start|stop|restart" is deprecated, please use "octoprint daemon start|stop|restart" from now on". But I can't remember seeing a note on it in the change log. Do I overlooked it or is it missing?

@foosel

This comment has been minimized.

Copy link
Owner

commented Dec 11, 2016

It is deprecated, not removed. Part of the new CLI. The old way should still work though (and did when I last tested it), only print that message before starting, then do the same thing as the new command. If it doesn't, that's a bug.

@malnvenshorn

This comment has been minimized.

Copy link
Contributor Author

commented Dec 11, 2016

It doesn't work the old way. Here is the output http://pastebin.com/583kmbMm

@foosel

This comment has been minimized.

Copy link
Owner

commented Dec 11, 2016

Apparently I managed to break that then.

@foosel foosel changed the title OctoPrint won't start after updating to 1.3.0 octoprint --daemon is broken in 1.3.0 Dec 12, 2016

@foosel

This comment has been minimized.

Copy link
Owner

commented Dec 12, 2016

Fixed in d0ff9cb / on maintenance. Will be released as part of 1.3.1 (RC for that probably within the week, full stable release after the holidays and new year's).

@foosel

This comment has been minimized.

Copy link
Owner

commented Dec 15, 2016

RC for that probably within the week

Small correction, that will have to wait until after New Year's, wrist issues are ruining my last couple of productive days this year, sorry.

@KeiroD

This comment has been minimized.

Copy link

commented Jan 17, 2017

That explains why I could not get the thing to work... I'd just updated it and was confused as to why it continued to show the service was active when it wasn't.

I even tried to update it to do "sudo octoprint serve" in the UI... but that didn't work, either... mostly for obvious reasons. I will note that octoprint serve does start OctoPrint accordingly but the background method of starting OctoPrint no longer works via sudo service octoprint start. It simply exits, so perhaps that needs to be also looked at?

Additional note: I applied the fix at line 149 in your maintenance branch to see if that'd change things, no go on that, I think.

This is on Minibian.

Relevant logs:

2017-01-17 12:37:25,428 - octoprint.server - INFO - Starting OctoPrint 1.3.0.post1+g1014712 (master branch)
2017-01-17 12:37:25,569 - octoprint.plugin.core - INFO - Loading plugins from /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins, /home/keiro/.octoprint/plugins and installed plugin packages...
2017-01-17 12:37:28,987 - octoprint.plugins.discovery - INFO - pybonjour is not installed, Zeroconf Discovery won't be available
2017-01-17 12:37:28,994 - octoprint.plugin.core - INFO - Found 7 plugin(s) providing 7 mixin implementations, 4 hook handlers
2017-01-17 12:37:29,052 - octoprint.plugin.core - INFO - Loading plugins from /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins, /home/keiro/.octoprint/plugins and installed plugin packages...
2017-01-17 12:37:29,728 - octoprint.plugin.core - INFO - Found 7 plugin(s) providing 7 mixin implementations, 4 hook handlers
2017-01-17 12:37:29,742 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/keiro/.octoprint/uploads...
2017-01-17 12:37:29,744 - octoprint.filemanager.storage - INFO - ... file metadata for /home/keiro/.octoprint/uploads initialized successfully.
2017-01-17 12:37:29,822 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2017-01-17 12:37:34,102 - octoprint.util.pip - INFO - Using "/usr/bin/python -m pip" as command to invoke pip
2017-01-17 12:37:38,418 - octoprint.util.pip - INFO - Version of pip is 9.0.1
2017-01-17 12:37:38,421 - octoprint.util.pip - INFO - pip installs to /usr/lib/python2.7/dist-packages, --user flag needed => yes, virtual env => no
2017-01-17 12:37:38,425 - octoprint.plugin.core - INFO - Initialized 7 plugin implementation(s)
2017-01-17 12:37:38,438 - octoprint.plugin.core - INFO - 7 plugin(s) registered with the system:
|  Announcement Plugin (bundled) = /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins/announcements
|  Core Wizard (bundled) = /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins/corewizard
|  CuraEngine (<= 15.04) (bundled) = /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins/cura
|  Discovery (bundled) = /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins/discovery
|  Plugin Manager (bundled) = /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins/pluginmanager
|  Software Update (bundled) = /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins/softwareupdate
|  Virtual Printer (bundled) = /usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/plugins/virtual_printer
2017-01-17 12:37:38,450 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2017-01-17 12:37:38,456 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2017-01-17 12:37:38,463 - octoprint.server - INFO - Reset webasset folder /home/keiro/.octoprint/generated/webassets...
2017-01-17 12:37:38,496 - octoprint.server - INFO - Reset webasset folder /home/keiro/.octoprint/generated/.webassets-cache...
2017-01-17 12:37:39,209 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance "SeolaTech Duplicator i3" for SSDP
2017-01-17 12:37:39,242 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2017-01-17 12:37:39,629 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2017-01-17 12:37:39,793 - octoprint.server - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'https://emberberry.heimkoma.com/octoprint/'}
^C2017-01-17 12:37:44,577 - octoprint.server - INFO - Shutting down...
2017-01-17 12:37:45,200 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2017-01-17 12:37:45,212 - octoprint.events - INFO - Event loop shut down
2017-01-17 12:37:45,226 - octoprint.server - INFO - Goodbye!
keiro@emberberry:~/OctoPrint$ sudo service octoprint start
keiro@emberberry:~/OctoPrint$ sudo service octoprint status
● octoprint.service - LSB: OctoPrint daemon
   Loaded: loaded (/etc/init.d/octoprint)
   Active: active (exited) since Tue 2017-01-17 12:37:50 CST; 5s ago
  Process: 1941 ExecStop=/etc/init.d/octoprint stop (code=exited, status=0/SUCCESS)
  Process: 2089 ExecStart=/etc/init.d/octoprint start (code=exited, status=0/SUCCESS)

Jan 17 12:37:50 emberberry octoprint[2089]: Starting OctoPrint Daemon: OctoPrint.
Jan 17 12:37:50 emberberry systemd[1]: Started LSB: OctoPrint daemon.
@foosel

This comment has been minimized.

Copy link
Owner

commented Jan 18, 2017

First of all please try either the full maintenance or rather rc/maintenance branch (which is 1.3.1rc1). That way we won't try to hunt after issues that have already been solved in what is going to be the new stable release probably within the week.

Try what happens when you do a octoprint --daemon start directly on the command line interface, does the server start then? How about octoprint daemon start (the new version)?

Also provide your /etc/init.d/octoprint file, because that is what's calling OctoPrint when you issue the service command and without knowing what's in there any attempts at debugging are just guess work. There was a bug in the shipped init script that might be causing your issue, see #1657, so make sure to update that script, maybe that already fixed things.

@foosel

This comment has been minimized.

Copy link
Owner

commented Jan 20, 2017

Never mind, I just found it I think.

@foosel foosel removed the status:solved label Jan 20, 2017

foosel added a commit that referenced this issue Jan 20, 2017

Fixed passing of "daemon" legacy parameter on CLI
This time this hopefully really solves #1641
@foosel

This comment has been minimized.

Copy link
Owner

commented Jan 20, 2017

Should now really be fixed on maintenance, devel and the new RC for 1.3.1 I just pushed for this, 1.3.1rc2 on the Maintenance RC release channel.

I couldn't reproduce any issues with the above commit anymore. I tested various permutations of octoprint --daemon start|stop, octoprint, octoprint serve and octoprint daemon start|stop, with --port and --pid parameters at various locations and things did what they should do for me.

If anyone is still running into issues with the deprecated commands, please specify exactly what you are calling how in which order and what it outputs.

@KeiroD

This comment has been minimized.

Copy link

commented Jan 21, 2017

Hi,

Will provide deets shortly.

From /etc/init.d/octoprint...

keiro@emberberry:~$ cat /etc/init.d/octoprint
#!/bin/sh

### BEGIN INIT INFO
# Provides:          octoprint
# Required-Start:    $local_fs networking
# Required-Stop:
# Should-Start:
# Should-Stop:
# Default-Start:     2 3 4 5
# Default-Stop:      0 1 6
# Short-Description: OctoPrint daemon
# Description:       Starts the OctoPrint daemon with the user specified in
#                    /etc/default/octoprint.
### END INIT INFO

# Author: Sami Olmari

PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin
DESC="OctoPrint Daemon"
NAME="OctoPrint"
PKGNAME=octoprint
PIDFILE=/var/run/$PKGNAME.pid
SCRIPTNAME=/etc/init.d/$PKGNAME

# Read configuration variable file if it is present
[ -r /etc/default/$PKGNAME ] && . /etc/default/$PKGNAME

# Exit if the DAEMON is not set
if [ -z "$DAEMON" ]
then
    log_warning_msg "Not starting $PKGNAME, DAEMON not set in /etc/default/$PKGNAME."
    exit 0
fi

# Exit if the DAEMON is not installed
[ -x "$DAEMON" ] || exit 0

# Load the VERBOSE setting and other rcS variables
[ -f /etc/default/rcS ] && . /etc/default/rcS

# Define LSB log_* functions.
# Depend on lsb-base (>= 3.0-6) to ensure that this file is present.
. /lib/lsb/init-functions

if [ -z "$START" -o "$START" != "yes" ]
then
   log_warning_msg "Not starting $PKGNAME, edit /etc/default/$PKGNAME to start it."
   exit 0
fi

if [ -z "$OCTOPRINT_USER" ]
then
    log_warning_msg "Not starting $PKGNAME, OCTOPRINT_USER not set in /etc/default/$PKGNAME."
    exit 0
fi

COMMAND_ARGS=
if [ -z "$BASEDIR" ]
then
    COMMAND_ARGS="--basedir $BASEDIR $COMMAND_ARGS"
fi

if [ -z "$CONFIGFILE" ]
then
    COMMAND_ARGS="--config $CONFIGFILE $COMMAND_ARGS"
fi

#
# Function to verify if a pid is alive
#
is_alive()
{
   pid=`cat $1` > /dev/null 2>&1
   kill -0 $pid > /dev/null 2>&1
   return $?
}

#
# Function that starts the daemon/service
#
do_start()
{
   # Return
   #   0 if daemon has been started
   #   1 if daemon was already running
   #   2 if daemon could not be started

   is_alive $PIDFILE
   RETVAL="$?"

   if [ $RETVAL != 0 ]; then
       start-stop-daemon --start --background --quiet --pidfile $PIDFILE --make-pidfile \
       --exec $DAEMON --chuid $OCTOPRINT_USER --user $OCTOPRINT_USER --umask $UMASK --nicelevel=$NICELEVEL \
       -- $COMMAND_ARGS serve $DAEMON_ARGS
       RETVAL="$?"
   fi
}

#
# Function that stops the daemon/service
#
do_stop()
{
   # Return
   #   0 if daemon has been stopped
   #   1 if daemon was already stopped
   #   2 if daemon could not be stopped
   #   other if a failure occurred

   start-stop-daemon --stop --quiet --retry=TERM/30/KILL/5 --user $OCTOPRINT_USER --pidfile $PIDFILE
   RETVAL="$?"
   [ "$RETVAL" = "2" ] && return 2

   rm -f $PIDFILE

   [ "$RETVAL" = "0"  ] && return 0 || return 1
}

case "$1" in
  start)
   [ "$VERBOSE" != no ] && log_daemon_msg "Starting $DESC" "$NAME"
   do_start
   case "$?" in
      0|1) [ "$VERBOSE" != no ] && log_end_msg 0 ;;
      2) [ "$VERBOSE" != no ] && log_end_msg 1 ;;
   esac
   ;;
  stop)
   [ "$VERBOSE" != no ] && log_daemon_msg "Stopping $DESC" "$NAME"
   do_stop
   case "$?" in
      0|1) [ "$VERBOSE" != no ] && log_end_msg 0 ;;
      2) [ "$VERBOSE" != no ] && log_end_msg 1 ;;
   esac
   ;;
  status)
   status_of_proc -p $PIDFILE $DAEMON $NAME && exit 0 || exit $?
   ;;
  restart)
   log_daemon_msg "Restarting $DESC" "$NAME"
   do_stop
   case "$?" in
     0|1)
      do_start
      case "$?" in
         0) log_end_msg 0 ;;
         1) log_end_msg 1 ;; # Old process is still running
         *) log_end_msg 1 ;; # Failed to start
      esac
      ;;
     *)
        # Failed to stop
      log_end_msg 1
      ;;
   esac
   ;;
  *)
   echo "Usage: $SCRIPTNAME {start|stop|status|restart}" >&2
   exit 3
   ;;
esac

As per your request to try octoprint --daemon start... the following output occurs:

keiro@emberberry:~$ sudo octoprint --daemon start
[sudo] password for keiro: 
Daemon operation via "octoprint --daemon start|stop|restart" is deprecated, please use "octoprint daemon start|stop|restart" from now on
Traceback (most recent call last):
  File "/usr/local/bin/octoprint", line 9, in <module>
    load_entry_point('OctoPrint==1.3.0.post1+g1014712', 'console_scripts', 'octoprint')()
  File "/usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/__init__.py", line 399, in main
    octo(args=args, prog_name="octoprint", auto_envvar_prefix="OCTOPRINT")
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/core.py", line 716, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/core.py", line 696, in main
    rv = self.invoke(ctx)
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/core.py", line 1037, in invoke
    return Command.invoke(self, ctx)
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/core.py", line 889, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/core.py", line 534, in invoke
    return callback(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/decorators.py", line 17, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/OctoPrint-1.3.0.post1+g1014712-py2.7.egg/octoprint/cli/__init__.py", line 149, in octo
    ctx.invoke(daemon_command, debug=debug, pid=pid, daemon=daemon, allow_root=allow_root)
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/core.py", line 534, in invoke
    return callback(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/decorators.py", line 64, in new_func
    return ctx.invoke(f, obj, *args[1:], **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/click-6.2-py2.7.egg/click/core.py", line 534, in invoke
    return callback(*args, **kwargs)
TypeError: daemon_command() got an unexpected keyword argument 'daemon'

So it looks like your latest commit fixes the issue I just described with the traceback. :)

@foosel

This comment has been minimized.

Copy link
Owner

commented Jan 24, 2017

That init script definitely also still contains the bug I mentioned, you need to update that to the fixed version, see #1657 for details.

I'll probably release 1.3.1 either today or tomorrow though, so far I haven't heard anything bad about RC2. It's always a bit tricky to juggle between "enough time for people to test the RCs" and "getting fixes out to people as fast as possible".

In general though I strongly suggest to switch to a fixed branch or even RC/release channel instead of manually applying individual patches - those ARE usually self contained, but I do not test each individual commit against master but only everything together.

@JohnOCFII

This comment has been minimized.

Copy link

commented Jan 25, 2017

I'll probably release 1.3.1 either today or tomorrow though, so far I haven't heard anything bad about RC2. It's always a bit tricky to juggle between "enough time for people to test the RCs" and "getting fixes out to people as fast as possible".

I've only run a few prints through 1.3.1.rc2, but seems fine so far.

@KeiroD

This comment has been minimized.

Copy link

commented Jan 25, 2017

Yeah, I'd updated to rc2, seems fine for me as well.

No hiccups so far. At the time, I had not updated to the newer rc when I'd cherry-picked the fix but updating to rc2 seems to have resolved the issue.

@foosel

This comment has been minimized.

Copy link
Owner

commented Jan 25, 2017

Part of 1.3.1 which has just been released.

@foosel foosel closed this Jan 25, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.