"No such file or directory" resurfaces

[Paul Everitt]

Our old friend has returned. Traceback below. In the past this has been related to trouble getting ~/bin/doctotext into the PATH of the app server. Usually a restart of the app server after a VM reboot was enough to fix it. I did so this time on all 3 app servers, to no avail. Perhaps we need to restart supervisord?

Error converting file /srv/osfkarl/production/35/var/blob_cache/osf/tmp/tmpnUgd2l

Traceback (most recent call last):
  File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/content/models/adapters.py", line 116, in _extract_file_data
    mimetype=context.mimetype)
  File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/utilities/converters/doc.py", line 39, in convert
    return self.execute('doctotext "%s"' % filename), 'utf-8'
  File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/utilities/converters/baseconverter.py", line 54, in execute
    close_fds=True)
  File "/usr/lib/python2.6/subprocess.py", line 623, in __init__
    errread, errwrite)
  File "/usr/lib/python2.6/subprocess.py", line 1141, in _execute_child
    raise child_exception
OSError: [Errno 2] No such file or directory

[Paul Everitt (paul-agendaless)]

Over to Chris, marked as high because we are getting numerous errors every day on this.

[Chris McDonough (chrism-plope)]

Grepping the logs for the error turned this up only on osfkarl12, in mailin.log.

I restarted the mailin process on that machine, and the warnings about not finding doctotext went away in the log so it should be fine now.

[Chris McDonough (chrism-plope)]

Also restarted mailin on osfkarl10 and 11

[Paul Everitt (paul-agendaless)]

We just got another of these alarms this morning. I'll clear the alarm to shut up Nagios. Chris, it is Fri Jan 31 11:16:11 2014

--Paul

On Jan 31, 2014, at 2:19 AM, Chris McDonough <email address hidden> wrote:

> Grepping the logs for the error turned this up only on osfkarl12, in
> mailin.log.
>
> I restarted the mailin process on that machine, and the warnings about
> not finding doctotext went away in the log so it should be fine now.
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1274114
>
> Title:
> "No such file or directory" resurfaces
>
> Status in KARL3:
> Fix Released
>
> Bug description:
> Our old friend has returned. Traceback below. In the past this has
> been related to trouble getting ~/bin/doctotext into the PATH of the
> app server. Usually a restart of the app server after a VM reboot was
> enough to fix it. I did so this time on all 3 app servers, to no
> avail. Perhaps we need to restart supervisord?
>
> Error converting file
> /srv/osfkarl/production/35/var/blob_cache/osf/tmp/tmpnUgd2l
>
> Traceback (most recent call last):
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/content/models/adapters.py", line 116, in _extract_file_data
> mimetype=context.mimetype)
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/utilities/converters/doc.py", line 39, in convert
> return self.execute('doctotext "%s"' % filename), 'utf-8'
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/utilities/converters/baseconverter.py", line 54, in execute
> close_fds=True)
> File "/usr/lib/python2.6/subprocess.py", line 623, in __init__
> errread, errwrite)
> File "/usr/lib/python2.6/subprocess.py", line 1141, in _execute_child
> raise child_exception
> OSError: [Errno 2] No such file or directory
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/karl3/+bug/1274114/+subscriptions

[Chris McDonough (chrism-plope)]

Unfortunately the logs which show this error have no timestamps. I restarted the search and mailout processes on osfkarl12; that's the only thing I can think of at this point. If that doesn't solve it we'll need to figure out which appserver and which process the error is coming from, which will mean we'll need to do some deployment stuff and add some logging.

[Paul Everitt (paul-agendaless)]

FWIW, I figured this bug would eventually lead to a commit for getting better forensics.

--Paul

On Jan 31, 2014, at 5:13 PM, Chris McDonough <email address hidden> wrote:

> Unfortunately the logs which show this error have no timestamps. I
> restarted the search and mailout processes on osfkarl12; that's the only
> thing I can think of at this point. If that doesn't solve it we'll need
> to figure out which appserver and which process the error is coming
> from, which will mean we'll need to do some deployment stuff and add
> some logging.
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1274114
>
> Title:
> "No such file or directory" resurfaces
>
> Status in KARL3:
> Fix Released
>
> Bug description:
> Our old friend has returned. Traceback below. In the past this has
> been related to trouble getting ~/bin/doctotext into the PATH of the
> app server. Usually a restart of the app server after a VM reboot was
> enough to fix it. I did so this time on all 3 app servers, to no
> avail. Perhaps we need to restart supervisord?
>
> Error converting file
> /srv/osfkarl/production/35/var/blob_cache/osf/tmp/tmpnUgd2l
>
> Traceback (most recent call last):
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/content/models/adapters.py", line 116, in _extract_file_data
> mimetype=context.mimetype)
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/utilities/converters/doc.py", line 39, in convert
> return self.execute('doctotext "%s"' % filename), 'utf-8'
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/utilities/converters/baseconverter.py", line 54, in execute
> close_fds=True)
> File "/usr/lib/python2.6/subprocess.py", line 623, in __init__
> errread, errwrite)
> File "/usr/lib/python2.6/subprocess.py", line 1141, in _execute_child
> raise child_exception
> OSError: [Errno 2] No such file or directory
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/karl3/+bug/1274114/+subscriptions

[Paul Everitt (paul-agendaless)]

Bringing this back to life. We're getting multiple alarms, every day, week after week. First step is for either Tres or Chris to change the error logging to capture hostname and which process (karl, mailin, etc.) triggered the exception.

[Tres Seaver (tseaver)]

When started from a "login shell", the PATH envvar is set to include '/srv/osfkarl/bin/', which is where 'doctotext' is installed. However, stuff which runs from cron (e.g 'supervisrod' running via '@reboot'?) the login environment may not be set.

Perhaps we should be adding 'environment' in supervisord.conf[1]?

    [program:mailin]
    command = %(here)s/../bin/karlserve mailin --daemon --interval 60
    redirect_stderr = true
    stdout_logfile = %(here)s/../var/log/mailin.log
    autostart = true
    environment = PATH="/srv/osfkarl/bin:/usr/local/bin:/usr/bin:/bin:/opt/bin:/usr/i686-pc-linux-gnu/gcc-bin/4.5.4:/srv/osfkarl/.local/bin"

[1] http://supervisord.org/subprocess.html#subprocess-environment

[Paul Everitt (paul-agendaless)]

Tres, do you have room on your plate this week to give a stab at it?

--Paul

On Feb 25, 2014, at 3:09 PM, Tres Seaver <email address hidden> wrote:

> When started from a "login shell", the PATH envvar is set to include
> '/srv/osfkarl/bin/', which is where 'doctotext' is installed. However,
> stuff which runs from cron (e.g 'supervisrod' running via '@reboot'?)
> the login environment may not be set.
>
> Perhaps we should be adding 'environment' in supervisord.conf[1]?
>
> [program:mailin]
> command = %(here)s/../bin/karlserve mailin --daemon --interval 60
> redirect_stderr = true
> stdout_logfile = %(here)s/../var/log/mailin.log
> autostart = true
> environment = PATH="/srv/osfkarl/bin:/usr/local/bin:/usr/bin:/bin:/opt/bin:/usr/i686-pc-linux-gnu/gcc-bin/4.5.4:/srv/osfkarl/.local/bin"
>
> [1] http://supervisord.org/subprocess.html#subprocess-environment
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1274114
>
> Title:
> "No such file or directory" resurfaces
>
> Status in KARL3:
> In Progress
>
> Bug description:
> Our old friend has returned. Traceback below. In the past this has
> been related to trouble getting ~/bin/doctotext into the PATH of the
> app server. Usually a restart of the app server after a VM reboot was
> enough to fix it. I did so this time on all 3 app servers, to no
> avail. Perhaps we need to restart supervisord?
>
> Error converting file
> /srv/osfkarl/production/35/var/blob_cache/osf/tmp/tmpnUgd2l
>
> Traceback (most recent call last):
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/content/models/adapters.py", line 116, in _extract_file_data
> mimetype=context.mimetype)
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/utilities/converters/doc.py", line 39, in convert
> return self.execute('doctotext "%s"' % filename), 'utf-8'
> File "/srv/osfkarl/production/35/eggs/karl-3.119-py2.6.egg/karl/utilities/converters/baseconverter.py", line 54, in execute
> close_fds=True)
> File "/usr/lib/python2.6/subprocess.py", line 623, in __init__
> errread, errwrite)
> File "/usr/lib/python2.6/subprocess.py", line 1141, in _execute_child
> raise child_exception
> OSError: [Errno 2] No such file or directory
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/karl3/+bug/1274114/+subscriptions

[Tres Seaver (tseaver)]

I will try tweaking the "environ=" bits in the supervisord config and
verify at least that it does no harm.

I may also add a new debug-only view which tries to locate all the
external programs used by the conversion stuff, and also dumps the
'os.environ' (and 'uptime'?) so that we can verify the hypothesis that
reboots are involved somehow.

[Tres Seaver (tseaver)]

I have added a '/debug_converters.html' admin view on the trunk, showing both the list of converters (with their commands and availability) and the os.environ:

  https://github.com/karlproject/karl/commit/60a5f2a978288bd1c072b96aca8193e49a058887

[Tres Seaver (tseaver)]

The report is now on staging:

  https://karlstaging.gocept.com/debug_converters.html

[Tres Seaver (tseaver)]

I'm part-way along to adding the 'environ=PATH="...."' bits to the osideploy-generated supervisord.conf:

  https://github.com/karlhosting/osideploy/commit/016223988ccd20a8b09b09c13cc71e30c36dfb46

It seems to generate correctly on my local box. I will try pushing to staging tomorrow and see if uploaded .doc files get indexed.

[Tres Seaver (tseaver)]

"This time for sure!" I just pushed a change to osideploy which seems
to DTRT setting the environment via supervisord for karl / search /
mailin:

  https://github.com/karlhosting/osideploy/commit/52e852174f4862202f79f17bec55ed1827a8e685

At least, the PATH looks like what I meant to configure on karlstaging:

  https://karlstaging.gocept.com/debug_converters.html

After searching and missing for files with 'mimsey' in them, I uploaded
this Word doc:

  https://karlstaging.gocept.com/communities/karl-developer-team/files/can_we_index_this.doc/

and could find it:

  https://karlstaging.gocept.com/searchresults.html?body=mimsey&kind=files

So, for the processes started by supervisord, I think we'll be able to
find 'doctotext'.

Now, if we can just get control of the crontab....

[Paul Everitt (paul-agendaless)]

Hallelujah, I believe this succeeded.