perfSONAR User Q&A and Other Discussion

[Andrew Lake <>]

Hi George,

Glad you were able to find the source of the issue. I captured the info you shared in a documentation issue. It sounds like we should make a note of that somewhere since it is not immediately obvious the cause but easy to run into. 

Thanks,
Andy

On Wed, Oct 3, 2018 at 4:35 PM Uhl, George D. (GSFC-423.0)[SGT INC] <> wrote:

Andy,

It turns out it was an selinux issue.  I’m running enforcing/active and somehow the esmond.log file was impacted after I attempted to migrate the data this morning.  I dug around and found an email from Jon Clausen dated Thurs Sep 14, 2017, 5:56 am and followed the procedure outlined (see below).  It worked – the HTTP 500 errors have stopped.  I’m going to change selinux to permissive and go from there.  How/why this stopped working is still unknown.

Thanks,

George

=============

Hi

Our measurement archive is installed from the CentOS 7 *.iso, with perfSonar

components installed from the internet2 repo.

I chose to leave SELinux active/enforcing, which is actually not causing

many problems, generally - to my pleasant surprise.

The system has yum-cron installed, so updates happen 'whenever'.

Early this morning there were a lot of package updates, and subsequently the

toolkit URL was unable to load test results, showing an 'internal server

error' message instead.

The cause turned out to be a change in SELinux 'type' on a couple of log

files, which resulted in permission denied errors in

/var/log/httpd/error_log

[Thu Sep 14 10:59:19.652856 2017] [:error] [pid 14147] [remote

109.105.99.90:132

] ValueError: Unable to configure handler 'esmond_handler': [Errno 13]

Permission denied: '/var/log/esmond/esmond.log'

The 'cure' would have been to change object type using chcon, or as I did:

move the log file out of the way and restart apache.

The object type change can be seen here:

[jac@psma01 ~]$ ls -Z /var/log/esmond/esmond.log*

-rw-r--r--. apache apache system_u:object_r:httpd_log_t:s0

/var/log/esmond/esmond.log

-rw-r--r--. apache apache system_u:object_r:var_log_t:s0

/var/log/esmond/esmond.log.2017-08-21

This mail is mostly a 'heads up' to other people running the measurement

archive under SELinux, but I guess the info may be relevant to the perfSonar

packagers too.

Should I submit the info somwhere?

br

/jon

-- 

 

From: <> on behalf of George Uhl <>
Date: Wednesday, October 3, 2018 at 4:12 PM
To: Andrew Lake <>
Cc: perfsonar-user <>
Subject: Re: [non-nasa source] [perfsonar-user] FW: http POST 500 527 errors on central archive

Andy,

The log files were not copied from the old server.  I did a chmod on esmond.log to 666 but that didn’t help either.

Thanks,

George

# ls -la /var/log/esmond

total 5056

drwxr-xr-x.  3 apache apache     177 Oct  3 14:23 .

drwxr-xr-x. 15 root   root      4096 Oct  3 19:11 ..

drwxr-xr-x.  2 apache apache       6 Mar 15  2018 crashlog

-rw-r--r--.  1 apache apache 5108885 Oct  3 14:52 django.log

-rw-r--r--.  1 apache apache    8230 Oct  3 14:23 django.log.1

-rw-r--r--.  1 apache apache    8480 Oct  3 14:23 django.log.2

-rw-r--r--.  1 apache apache    8480 Oct  3 14:23 django.log.3

-rw-r--r--.  1 apache apache   12720 Oct  3 14:23 django.log.4

-rw-r--r--.  1 apache apache    4240 Oct  3 14:23 django.log.5

-rw-rw-rw-.  1 apache apache       0 Mar 15  2018 esmond.log

-rw-r--r--.  1 apache apache       0 Mar 15  2018 install.log

From: Andrew Lake <>
Date: Wednesday, October 3, 2018 at 4:00 PM
To: George Uhl <>
Cc: perfsonar-user <>
Subject: Re: [non-nasa source] [perfsonar-user] FW: http POST 500 527 errors on central archive

Hi George,

The error you are seeing is about the log permissions. Make sure the log files under /var/log/esmond are owned by the "apache" user then restart httpd. Did you copy over logs from the old host as well?

Thanks,
Andy

On Wed, Oct 3, 2018 at 3:51 PM Uhl, George D. (GSFC-423.0)[SGT INC] <> wrote:

It appears that the existing user api key was overwritten during the migration process.  Running both

/usr/sbin/esmond_manage add_ps_metadata_post_user

/usr/sbin/esmond_manage add_timeseries_post_user

reveal that the Key was changed to the value in the old archive for the user.  Changing the auth-token

in the archives.d/*.json file on the testpoint servers didn’t help. I’m still getting HTTP  500 errors.

-George

From: <> on behalf of George Uhl <>
Date: Wednesday, October 3, 2018 at 1:52 PM
To: "" <>
Subject: [non-nasa source] [perfsonar-user] FW: http POST 500 527 errors on central archive

From: George Uhl <>
Date: Wednesday, October 3, 2018 at 1:38 PM
To: "" <>
Subject: http POST 500 527 errors on central archive

I attempted to migrate data from an older pS archive to one built on pS 4.1 by following these instructions.  Unfortunately once I had completed the migration none of my pS testpoint servers are able to post data into esmond. Now I’m getting Code 500 errors instead.

Thanks,

George

From ssl error log:

Wed Oct 03 17:30:37.021250 2018] [:error] [pid 2836] [remote x.x.x.x:y] mod_wsgi (pid=2836): Exception occurred processing WSGI script ‘/usr/lib/esmond/esmond/wsgi.py’.

[Wed Oct 03 17:30:37.021312 2018] [:error] [pid 2836] [remote x.x.x.x:y] Traceback (most recent call last):

[Wed Oct 03 17:30:37.021344 2018] [:error] [pid 2836] [remote x.x.x.x:y]   File "/usr/lib/esmond/esmond/wsgi.py", line 28, in application

[Wed Oct 03 17:30:37.021433 2018] [:error] [pid 2836] [remote x.x.x.x:y]     return get_wsgi_application()(environ, start_response)

[Wed Oct 03 17:30:37.021452 2018] [:error] [pid 2836] [remote x.x.x.x:y]   File "/usr/lib/esmond/lib/python2.7/site-packages/django/core/wsgi.py", line 13, in get_wsgi_application

[Wed Oct 03 17:30:37.021482 2018] [:error] [pid 2836] [remote x.x.x.x:y]     django.setup(set_prefix=False)

[Wed Oct 03 17:30:37.021496 2018] [:error] [pid 2836] [remote x.x.x.x:y]   File "/usr/lib/esmond/lib/python2.7/site-packages/django/__init__.py", line 22, in setup

[Wed Oct 03 17:30:37.021520 2018] [:error] [pid 2836] [remote x.x.x.x:y]     configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)

[Wed Oct 03 17:30:37.021533 2018] [:error] [pid 2836] [remote x.x.x.x:y]   File "/usr/lib/esmond/lib/python2.7/site-packages/django/utils/log.py", line 75, in configure_logging

[Wed Oct 03 17:30:37.021558 2018] [:error] [pid 2836] [remote x.x.x.x:y]     logging_config_func(logging_settings)

[Wed Oct 03 17:30:37.021572 2018] [:error] [pid 2836] [remote x.x.x.x:y]   File "/usr/lib64/python2.7/logging/config.py", line 803, in dictConfig

[Wed Oct 03 17:30:37.021597 2018] [:error] [pid 2836] [remote x.x.x.x:y]     dictConfigClass(config).configure()

[Wed Oct 03 17:30:37.021610 2018] [:error] [pid 2836] [remote x.x.x.x:y]   File "/usr/lib64/python2.7/logging/config.py", line 585, in configure

[Wed Oct 03 17:30:37.021633 2018] [:error] [pid 2836] [remote x.x.x.x:y]     '%r: %s' % (name, e))

[Wed Oct 03 17:30:37.021662 2018] [:error] [pid 2836] [remote x.x.x.x:y] ValueError: Unable to configure handler 'esmond_handler': [Errno 13] Permission denied: '/var/log/esmond/esmond.log'

From ssl request log:

[03/Oct/2018:17:35:42 +0000] x.x.x.x TLSv1.2 ECDHE-RSA-AES128-GCM-SHA256 "POST /esmond/perfsonar/archive/ HTTP/1.1" 527

From ssl access log:

x.x.x.x - - [03/Oct/2018:17:35:28 +0000] “POST /esmond/perfsonar/archive/ HTTP/1.1” 500 527