[LON-CAPA-admin] {Disarmed} Re: Published resources not showing up on access servers
Bob Gonzales
rgonzal at binghamton.edu
Sat Sep 19 09:59:56 EDT 2015
Things are getting worse for me here. I rebooted my library server this
morning hoping that might cure the ‘not found’ issue. But it didn’t and I
ended up with more weirdness.
Now when I try to log into my test course from any of my access servers I
get this message:
Map not loaded: The file
/home/httpd/html/userfiles/binghamton/71215825fc2344762binghamtonl1/default.sequence
does not exist.
and I get sent back to the roles screen. I look on binghamtonl1 and this
file does not exist.
Looking in lonnet on the library server I see this during and after the
reboot:
Sat Sep 19 08:40:43 2015 (15857): caching of id ->
dns%3a%2fadm%2fdns%2fhosts failed
Sat Sep 19 08:40:44 2015 (15857): Name loncapa.brs.cgresd.net no IP found
Sat Sep 19 08:40:50 2015 (15857): Name tuvok.physast.uga.edu no IP found
Sat Sep 19 08:40:50 2015 (15857): Name BCHS-CAPA.jeffco.k12.co.us no IP
found
Sat Sep 19 08:40:51 2015 (15857): Name loncapa.nfcc.edu no IP found
Sat Sep 19 08:40:52 2015 (15857): caching of id -> iphost%3aiphost failed
Sat Sep 19 08:40:56 2015 (8569): Failed to flush log buffer for
binghamton_71215825fc2344762binghamtonl1
Sat Sep 19 08:40:56 2015 (8572): Failed to flush log buffer for
binghamton_71215825fc2344762binghamtonl1
Sat Sep 19 08:40:56 2015 (2602): Failed to flush log buffer for
binghamton_71215825fc2344762binghamtonl1
Sat Sep 19 08:40:56 2015 (3204): Failed to flush log buffer for
binghamton_71215825fc2344762binghamtonl1
Sat Sep 19 08:40:56 2015 (8570): Failed to flush log buffer for
binghamton_71215825fc2344762binghamtonl1
Sat Sep 19 08:40:56 2015 (8551): Failed to flush log buffer for
binghamton_71215825fc2344762binghamtonl1
Sat Sep 19 08:40:56 2015 (3202): Failed to flush log buffer for
binghamton_71215825fc2344762binghamtonl1
Sat Sep 19 08:41:06 2015 (8569): Shutting down
Sat Sep 19 08:41:06 2015 (3202): Failed to flush log buffer for
binghamton_4231791afc6bb5593binghamtona6
Sat Sep 19 08:41:06 2015 (2602): Shutting down
Sat Sep 19 08:41:06 2015 (8572): Shutting down
Sat Sep 19 08:41:06 2015 (3204): Shutting down
Sat Sep 19 08:42:06 2015 (8570): Shutting down
Sat Sep 19 08:43:04 2015 (1362): <font color="yellow">INFO: Read
configuration</font>
Sat Sep 19 08:43:04 2015 (1362): Detected 64bit platform (1)
Sat Sep 19 08:43:04 2015 (1362): unable to contact DNS defaulting to on
disk file dns_hosts.tab
Sat Sep 19 08:43:04 2015 (1362): Name vita.ostfalia.de no IP found
Sat Sep 19 08:43:04 2015 (1362): Name loncapa2.vcu.edu no IP found
Sat Sep 19 08:43:04 2015 (1362): Name loncapa.et-inf.fho-emden.de no IP
found
Sat Sep 19 08:43:04 2015 (1362): Name loncapa.calpoly.edu no IP found
this goes on for all the servers.
Thinking that something in the OS didn’t finish starting before lon-capa, I
restarted lon-capa via loncontrol.
That cleared up ‘unable to contact DNS defaulting to on disk file
dns_hosts.tab’ message and
now I see this in lonnet which seems to always be there:
Sat Sep 19 08:48:36 2015 (2812): <font color="yellow">INFO: Read
configuration</font>
Sat Sep 19 08:48:36 2015 (2812): Detected 64bit platform (1)
Sat Sep 19 08:49:04 2015 (2825): <font color="yellow">INFO: Read
configuration</font>
Sat Sep 19 08:49:04 2015 (2825): Detected 64bit platform (1)
Sat Sep 19 08:49:05 2015 (2825): caching of id ->
dns%3a%2fadm%2fdns%2fhosts failed
Sat Sep 19 08:49:05 2015 (2825): Name loncapa.brs.cgresd.net no IP found
Sat Sep 19 08:49:05 2015 (2825): Name tuvok.physast.uga.edu no IP found
Sat Sep 19 08:49:05 2015 (2825): Name BCHS-CAPA.jeffco.k12.co.us no IP found
Sat Sep 19 08:49:06 2015 (2825): Name loncapa.nfcc.edu no IP found
Sat Sep 19 08:49:06 2015 (2825): caching of id -> iphost%3aiphost failed
Sat Sep 19 08:49:07 2015 (2980): <font color="yellow">INFO: Read
configuration</font>
Sat Sep 19 08:49:07 2015 (2980): Detected 64bit platform (1)
Sat Sep 19 08:49:07 2015 (2980): <span style='color:yellow;'>INFO: Read
file types</span>
Sat Sep 19 08:49:07 2015 (2980): caching of id ->
dns%3a%2fadm%2fdns%2fhosts failed
Sat Sep 19 08:49:08 2015 (2980): caching of id ->
dns%3a%2fadm%2fdns%2fdomain failed
Sat Sep 19 08:49:08 2015 (2980): Name loncapa.brs.cgresd.net no IP found
Sat Sep 19 08:49:08 2015 (2980): Name tuvok.physast.uga.edu no IP found
Sat Sep 19 08:49:08 2015 (2980): Name BCHS-CAPA.jeffco.k12.co.us no IP found
Sat Sep 19 08:49:08 2015 (2980): Name loncapa.nfcc.edu no IP found
Sat Sep 19 08:49:08 2015 (2980): caching of id -> iphost%3aiphost failed
Sat Sep 19 08:49:11 2015 (2995): <font color="yellow">INFO: Read
configuration</font>
Sat Sep 19 08:49:11 2015 (2995): Detected 64bit platform (1)
Sat Sep 19 08:49:13 2015 (3012): <font color="yellow">INFO: Read
configuration</font>
Sat Sep 19 08:49:13 2015 (3012): Detected 64bit platform (1)
Sat Sep 19 08:49:14 2015 (3013): Name loncapa.brs.cgresd.net no IP found
Sat Sep 19 08:49:14 2015 (3013): Name tuvok.physast.uga.edu no IP found
Sat Sep 19 08:49:14 2015 (3013): Name BCHS-CAPA.jeffco.k12.co.us no IP found
Sat Sep 19 08:49:14 2015 (3013): Name loncapa.nfcc.edu no IP found
I still have the ‘Map not loaded: The file
/home/httpd/html/userfiles/binghamton/71215825fc2344762binghamtonl1/default.sequence
does not exist’ message and cannot get into my test course.
Any ideas?
Thanks,
Bob Gonzales
On Fri, Sep 18, 2015 at 12:43 PM, Bob Gonzales <rgonzal at binghamton.edu>
wrote:
> Stuart,
>
> In my library servier httpd error_log I see:
>
> [Thu Sep 17 10:49:37.441421 2015] [:error] [pid 2605] access to
> /home/httpd/html/raw/binghamton/gonzales/Testing Area/foobar.problem failed
> for 128.226.130.9, reason: binghamtona2 not subscribed
>
> The subscription file shows the access server is subscribed.
>
> binghamtona2:128.226.130.9:1442502030
>
>
> Using the info in the referenced post
> http://mail.lon-capa.org/pipermail/lon-capa-admin/2013-November/002773.html,
> I'm thinking a name/ip problem.
>
> So, regarding entries in /etc/hosts, there are only the default ones for
> 127.0.0.1 and ::1 on all the machines.
>
> Looking at dns_hosts.tab I see this on all the servers (access and
> library):
>
> binghamtonl1:binghamton:library:loncapal1.chem.binghamton.edu:http:
> binghamton.edu
> binghamtona2:binghamton:access:loncapa2.chem.binghamton.edu:http:
> binghamton.edu
> binghamtona3:binghamton:access:loncapa3.chem.binghamton.edu:http:
> binghamton.edu
> binghamtona4:binghamton:access:loncapa.chem.binghamton.edu:http:
> binghamton.edu
> binghamtona5:binghamton:access:loncapa5.chem.binghamton.edu:http:
> binghamton.edu
> binghamtona6:binghamton:access:loncapa6.chem.binghamton.edu:http:
> binghamton.edu
> binghamtona7:binghamton:access:loncapa7.chem.binghamton.edu:http:
> binghamton.edu
>
> Looking at hosts I see this on the library server:
>
> ^s10.lite.msu.edu
> ^dalton.chem.sfu.ca
> ^library1.lon-capa.uiuc.edu
> binghamtonl1:binghamton:library:loncapal1.chem.binghamton.edu:http:
> binghamton.edu
>
> and this on one of the access servers:
> ^s10.lite.msu.edu
> ^dalton.chem.sfu.ca
> ^library1.lon-capa.uiuc.edu
> binghamtona2:binghamton:access:loncapa2.chem.binghamton.edu:http:
> chem.binghamton.edu
>
> I see binghamton.edu in the dns_hosts.tab and and hosts.tab on the
> library server but I see chem.binghamton.edu in the access servers
> hosts.tab. My dns domain is chem.binghamton.edu and I do remember using
> that during the installation on each machine this summer. Could this be
> it?
>
> Thanks,
> Bob Gonzales
>
>
>
> On Thu, Sep 17, 2015 at 5:23 PM, Stuart Raeburn <raeburn at msu.edu> wrote:
>
>> Hi Bob,
>>
>> Looking at lonc.log on the MSU LON-CAPA library server s10 I see that the
>> run of /home/httpd/perl/loncron used to update connections and retrieve
>> updated cluster membership information failed to connect to binghamtona2 at
>> 5:11 am today.
>>
>> On the MSU library server ...
>>
>> Thu Sep 17 05:11:14 2015 (2148) [loncapa2.chem.binghamton.edu] [Thu Sep
>> 17 05:11:14 2015: Parent keeping the flock] <font color='red'>CRITICAL:
>> Forking server for loncapa2.chem.binghamton.edu</font>
>> Thu Sep 17 05:11:18 2015 (13722) [loncapa2.chem.binghamton.edu] [Thu Sep
>> 17 05:11:14 2015: Connected to loncapa2.chem.binghamton.edu] <font
>> color='red'>CRITICAL: Failed to make a connection with lond.</font>
>> Thu Sep 17 05:11:18 2015 (13722) [loncapa2.chem.binghamton.edu] [Thu Sep
>> 17 05:11:14 2015: Connected to loncapa2.chem.binghamton.edu] <font
>> color='blue'>WARNING: Failing transaction sethost</font>
>>
>> As a result the lonc status reported on s10 for
>> loncapa2.chem.binghamton.edu was:
>>
>> www 13722 2148 0 05:11 ? 00:00:00 lonc:
>> loncapa2.chem.binghamton.edu Connection count: 0 Retries remaining: 5 ()
>> Thu Sep 17 13:29:08 2015
>>
>> However, when I attempted to connect to binghamtona2 a few hours ago the
>> connection was successfully created:
>>
>> www 13722 2148 0 05:11 ? 00:00:00 lonc:
>> loncapa2.chem.binghamton.edu Connection count: 1 Retries remaining: 5
>> (insecure) Thu Sep 17 13:34:39 2015
>>
>> and I was able to transfer my user session there.
>>
>> From the lonc.log information on your library server ...
>>
>> Thu Sep 17 11:05:19 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:53:24 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='green'>SUCCESS: Connection 1 to
>>> loncapa2.chem.binghamton.edu now ready for action</font>
>>> Thu Sep 17 11:10:20 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 11:10:20 2015: loncapa2.chem.binghamton.edu Connection count: 1
>>> Retries
>>> remaining: 5 (insecure)] <font color='blue'>WARNING: Shutting down a
>>> socket</font>
>>>
>>
>> This indicates successful creation of a connection, and then shutdown 5
>> minutes later, as a result of pruning of idle connections (this is all as
>> expected). The IdleTimeout hard-coded in /home/httpd/perl/loncnew is 5
>> minutes.
>>
>> Thu Sep 17 10:53:24 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:42:10 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='yellow'>INFO: Resetting Connection
>>> Retries.</font>
>>>
>>
>> This occurs when &Apache::lonnet::reconlonc() sends "reset_retries".
>> &reconlonc($clientname) is called in lond when lond is connected by a known
>> client (excluding connections from itself).
>>
>> Cleanup phase: Notifications
>>>
>>> Notifying host binghamtona7:not_found
>>> Notifying host binghamtona2:not_found
>>>
>>
>> The logged "not_found" messages originate from
>> lond::update_resource_handler() on the library server, and will be sent if
>> the old copy of the file which has just been republished is no longer
>> present on the access server.
>>
>> That can happen if the Linux OS on the access server was updated without
>> preserving the contents of /home/httpd/html/res/. This is not an issue,
>> including the case where the access server had a subscription to the file
>> before the access server was updated/rebuilt. When the file is requested
>> in a user session hosted on the access server it should be replicated to
>> the access server from the library server, as usual.
>>
>> However this:
>>
>> Thu Sep 17 11:00:30 2015 (3908): <font color="blue">WARNING: LWP get:
>>> 403 Forbidden: /home/httpd/html/res/binghamton/gonzales/Testing
>>> Area/foobar.problem</font>
>>>
>>>
>> indicates that the replication failed. You might check in the
>> corresponding Apache error_log file for the request for:
>>
>> GET /raw/binghamton/gonzales/TestingArea/foobar.problem
>>
>> from 128.226.130.9.
>>
>> See:
>>
>>
>> http://mail.lon-capa.org/pipermail/lon-capa-admin/2013-November/002773.html
>>
>> for a discussion of things to check. In that particular instance the
>> "Forbidden" error was caused by an incorrect IP address in /etc/hosts
>>
>> Stuart Raeburn
>> LON-CAPA Academic Consortium
>>
>>
>> Quoting Bob Gonzales <rgonzal at binghamton.edu>:
>>
>> Hi,
>>>
>>> I'm running 2.11.1 and centos 7.1 on all my servers.
>>>
>>> When I publish a resource and then try to access it on any of my access
>>> servers I get the message 'unable to find' and then the name of the
>>> problem
>>> just published.
>>>
>>> The subscription file for the problem shows the access server has
>>> subscribed.
>>>
>>> When I republished a file the log file for the problem I got the
>>> following
>>> information from the log file for the problem:
>>>
>>> Cleanup phase: Notifications
>>>
>>> Notifying host binghamtona7:not_found
>>> Notifying host binghamtona2:not_found
>>> Notifying course binghamton_71215825fc2344762binghamtonl1:ok
>>>
>>> I see a lot of these messages for binghamtona2 (loncapa2) in the library
>>> server lonnet.log
>>>
>>> Thu Sep 17 10:53:24 2015 (8257): Trying to reconnect lonc for
>>> binghamtona2 (
>>> loncapa2.chem.binghamton.edu)
>>>
>>> And these in the library servers lonc.log
>>>
>>> Thu Sep 17 10:42:10 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:42:10 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='yellow'>INFO: Resetting Connection
>>> Retries.</font>
>>> Thu Sep 17 10:53:24 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:42:10 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='yellow'>INFO: Resetting Connection
>>> Retries.</font>
>>> Thu Sep 17 10:53:24 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:53:24 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='yellow'>INFO: Resetting Connection
>>> Retries.</font>
>>> Thu Sep 17 10:53:24 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:53:24 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='yellow'>INFO: Resetting Connection
>>> Retries.</font>
>>> Thu Sep 17 11:05:19 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:53:24 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='green'>SUCCESS: Created connection 1 to
>>> host
>>> loncapa2.chem.binghamton.edu</font>
>>> Thu Sep 17 11:05:19 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:53:24 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='yellow'>INFO: Connected to lond version:
>>> 489</font>
>>> Thu Sep 17 11:05:19 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 10:53:24 2015: loncapa2.chem.binghamton.edu Connection count: 0
>>> Retries
>>> remaining: 5 ()] <font color='green'>SUCCESS: Connection 1 to
>>> loncapa2.chem.binghamton.edu now ready for action</font>
>>> Thu Sep 17 11:10:20 2015 (3279) [loncapa2.chem.binghamton.edu] [Thu
>>> Sep
>>> 17 11:10:20 2015: loncapa2.chem.binghamton.edu Connection count: 1
>>> Retries
>>> remaining: 5 (insecure)] <font color='blue'>WARNING: Shutting down a
>>> socket</font>
>>>
>>> I also see this in the access servers lonnet.log:
>>>
>>> Thu Sep 17 11:00:30 2015 (3908): <font color="blue">WARNING: LWP get:
>>> 403 Forbidden: /home/httpd/html/res/binghamton/gonzales/Testing
>>> Area/foobar.problem</font>
>>>
>>> I don't really know what all of this means. Any help would be
>>> appreciated.
>>>
>>> Thanks,
>>> Bob Gonzales
>>> Binghamton University
>>> Chemistry Dept
>>>
>>
>> _______________________________________________
>> LON-CAPA-admin mailing list
>> LON-CAPA-admin at mail.lon-capa.org
>> http://mail.lon-capa.org/mailman/listinfo/lon-capa-admin
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.lon-capa.org/pipermail/lon-capa-admin/attachments/20150919/42fb5c2d/attachment-0001.html>
More information about the LON-CAPA-admin
mailing list