Forum LAMS for Tech-Heads - General Forum: Error adding lams lesson activity in Moodle

By: Dave Bauer

[ Reply | Forward ]

We are also seeing, when we choose Lamsv2 from the add activity menu, in place of the tree menu of lams sequences to choose from this message:

"HTTP Error: socket read of headers timed out"

Not sure where or how to fix this. it should not be a problem. If I reload the page in my browser this message goes away and I see the tree. It might be that these two problems are related.

Posted by Dave Bauer

By: Jun-Dir Liew

[ Reply | Forward ]

Yes, this seems strange... might be worth seeing what LAMS is saying when it receives the request to get the list of learning designs. It should be a call to /lams/services/xml/LearningDesignRepository?bunchofparams.

Posted by Jun-Dir Liew

By: Dave Bauer

[ Reply | Forward ]

So basically what I would like to know is where does the lesson_id get filled in? I assume somehow the lams server has to provide that info. It doesn't look like there is any background xmlhttp calls going on in that form.

Posted by Dave Bauer

By: Jun-Dir Liew

[ Reply | Forward ]

The lesson_id is provided by LAMS after the module makes a call to create a lesson based on a sequence_id. When you submit the form, lamstwo_add_instance in lib.php gets called which makes the soap call to LAMS - and this is when it saves the lams lesson_id in the mdl_lamstwo table.

Posted by Jun-Dir Liew

By: Dave Bauer

[ Reply | Forward ]

I put some debugging statements in

and I get this:

Thu Sep 18 09:52:51 2008] [error] [client 74.76.1.174] Start lamstwo_get_lesson
, referer: http://ctcconline.org/course/mod.php?id=29§ion=1&sesskey=n1tOznl3
2R&add=lamstwo
[Thu Sep 18 09:52:51 2008] [error] [client 74.76.1.174] September 18,2008 9:52 a
msgadminmoodlemoodle, referer: course/mod.php?id=29§io
n=1&sesskey=n1tOznl32R&add=lamstwo
[Thu Sep 18 09:52:56 2008] [error] [client 74.76.1.174] HTTP Error: socket read
of headers timed out, referer: course/mod.php?id=29§io
n=1&sesskey=n1tOznl32R&add=lamstwo

So the headers time out error is recurring when the lesson is added but the lesson is added with a 0 lesson_id instead of retrying the http connection or returning an error message.

ANy idea how to diagnose the timeout problems? Can I increase the timeout? This happens in both places when getting the list of sequences and when getting the new lesson.

Posted by Dave Bauer

By: Dave Bauer

[ Reply | Forward ]

I went into nusoap.php
and I increased the connection_timeout parameter from 0 to 30 in every case where it was set.

This seems to have fixed the problem. It might be that lams soap call is just taking slightly longer than the soap client expected.

Posted by Dave Bauer

By: Dave Bauer

[ Reply | Forward ]

Nope!

I still get socket read of headers timeout error.

Is there another place some timeout setting could be increased? It is NOT taking more than 1 or 2 seconds to add the lesson to moodle, so its getting nowhere near the 30 second timeout I have set.

Posted by Dave Bauer

By: Jun-Dir Liew

[ Reply | Forward ]

The call to add the lesson is a soap call, but the call to get the tree of sequences isn't, and doesn't use nusoap.

> If I reload the page in my browser this message goes away and I see the tree.

This sounds like it may not be strictly a timeout problem. Have you checked the lams logs? Under $JBOSS_HOME/server/default/log/, lams.log, server.log, and localhost_access_{date}.log.

Posted by Jun-Dir Liew

By: Dave Bauer

[ Reply | Forward ]

Here is a message from lams server.log

07:43:39,599 ERROR [org.apache.catalina.core.ContainerBase.[jboss.web].[localhos
t].[/lams].[LoginRequest]] Servlet.service() for servlet LoginRequest threw exce
ption
org.lamsfoundation.lams.lesson.service.LessonServiceException: Lesson 0 does not
exist. Unable to add staff member to lesson.
        at org.lamsfoundation.lams.lesson.service.LessonService.addStaffMember(L
essonService.java:426)
        at org.lamsfoundation.lams.lesson.service.LessonService$$FastClassByCGLI
B$$209c1a6b.invoke(<generated>)
        at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:149)
        at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocatio
n.invokeJoinpoint(Cglib2AopProxy.java:685)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:148)
        at org.springframework.transaction.interceptor.TransactionInterceptor.in
voke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:170)
        at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterc
eptor.intercept(Cglib2AopProxy.java:623)
        at org.lamsfoundation.lams.lesson.service.LessonService$$EnhancerByCGLIB
$$76bec1a2.addStaffMember(<generated>)
        at org.lamsfoundation.lams.integration.util.LoginRequestDispatcher.addUs
erToLessonClass(LoginRequestDispatcher.java:164)
        at org.lamsfoundation.lams.integration.util.LoginRequestDispatcher.getRe
questURL(LoginRequestDispatcher.java:100)
        at org.lamsfoundation.lams.web.LoginRequestServlet.doGet(LoginRequestSer
vlet.java:131)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:697)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appl
icationFilterChain.java:252)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationF
ilterChain.java:173)
        at org.springframework.orm.hibernate3.support.OpenSessionInViewFilter.do
FilterInternal(OpenSessionInViewFilter.java:174)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerR
equestFilter.java:77)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appl
icationFilterChain.java:202)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationF
ilterChain.java:173)
        at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFi
lter.java:81)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appl
icationFilterChain.java:202)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationF
ilterChain.java:173)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperV
alve.java:213)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextV
lve.java:178)
        at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrinc
ipalValve.java:39)
        at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(Securit
yAssociationValve.java:153)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(Authentica
torBase.java:407)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(Authentica
torBase.java:407)
        at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValv
e.java:59)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.j
ava:126)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.j
ava:105)
        at org.lamsfoundation.lams.integration.security.SingleSignOn.invoke(Sing
leSignOn.java:121)
        at org.lamsfoundation.lams.integration.security.LoginRequestValve.invoke
(LoginRequestValve.java:67)
        at org.apache.catalina.valves.FastCommonAccessLogValve.invoke(FastCommon
AccessLogValve.java:481)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineVal
ve.java:107)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.jav
a:148)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java
:856)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.proce
ssConnection(Http11Protocol.java:744)
        at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpo
int.java:527)
        at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWor
kerThread.java:112)
        at java.lang.Thread.run(Thread.java:619)
07:44:17,445 WARN  [org.apache.struts.util.RequestUtils] No FormBeanConfig found
under 'AuthoringAction'
07:44:17,567 WARN  [org.apache.struts.util.RequestUtils] No FormBeanConfig found
under 'AuthoringAction'
07:44:20,231 WARN  [org.apache.struts.util.RequestUtils] No FormBeanConfig found
under 'AuthoringAction'
07:44:38,856 WARN  [org.apache.struts.util.RequestUtils] No FormBeanConfig found
under 'AuthoringAction'
07:44:39,192 WARN  [org.apache.struts.util.RequestUtils] No FormBeanConfig found
under 'AuthoringAction'



I did not see anything interesting in the lams.log.

Where can I look next?

Posted by Dave Bauer

By: Dave Bauer

[ Reply | Forward ]

To me this looks like this is an error in Lams that the lesson_id is not generated correctly, but I don't see any additional errors except the one I posted.

Posted by Dave Bauer

By: Jun-Dir Liew

[ Reply | Forward ]

This error is just a result of Moodle using a lesson id of 0, which isn't valid.

I do remember a problem similar to this where the lamstwo module was installed with an error - basically MySQL was in strict mode, and the mdl_lamstwo table failed to get created. This resulted in Moodle always using a lesson_id of 0. Can you check if this is the case?

Failing that, can you have a look at the lams access log - there should be records of Moodle's request to the LearningDesignRepository servlet (GET request) and the LessonManager service (SOAP request). Check the return codes of these requests to see if they returned successfully. Also, you can copy the LearningDesignRepository GET request and paste it into your browser, and you should get some XML representing the sequence info.

Posted by Jun-Dir Liew

By: Dave Bauer

[ Reply | Forward ]

Still getting this error, when clicking create sequence.

One user is getting this error. I can't reproduce the problem, even logging in as the particular user.

206.192.23.64 - - [14/Apr/2009:08:22:25 -0500] "GET /lams/services/LearningDesig
nRepositoryService?wsdl HTTP/1.1" 200 2836
206.192.23.64 - - [14/Apr/2009:08:22:45 -0500] "POST /lams/services/LearningDesi
gnRepositoryService HTTP/1.0" 200 42234
66.152.251.44 - mdl_ckelley [14/Apr/2009:08:22:49 -0500] "GET /lams/LoginRequest
?uid=ckelley&method=author&ts=April+14%2C2009+8%3A22+am&sid=moodle&hash=078f54bd
77556d2e0abf765ce9e5d8a9748f54df&courseid=29&country=US&lang=en&requestSrc=CCC%2
0Online%20Learning¬ifyCloseURL=http%3A//ctcconline.org/course/mod.php%3Fid%3D
29%26section%3D5%26sesskey%3DXz4UYy1itE%26add%3Dlamstwo HTTP/1.1" 302 -
66.152.251.44 - mdl_ckelley [14/Apr/2009:08:22:49 -0500] "GET /lams/home.do?meth
od=author&requestSrc=CCC+Online+Learning¬ifyCloseURL=http%3A%2F%2Fctcconline.
org%2Fcourse%2Fmod.php%3Fid%3D29%26section%3D5%26sesskey%3DXz4UYy1itE%26add%3Dla
mstwo HTTP/1.1" 200 2081

Those are the HTTP requests that I can find in the access logs. There isn't any XML I can see, what log file should I be looking in? This is the localhost_access_log

Posted by Dave Bauer

By: Dave Bauer

[ Reply | Forward ]

I also can't find anything in the server.log that corresponds to the time of those requests in the access log.

Posted by Dave Bauer

By: Dave Bauer

[ Reply | Forward ]

Ok, restarting LAMS seems ot have worked. Must be some sort of out-of-memory error that doesn't get written to the logs. Very strange.

Posted by Dave Bauer

By: Ernie Ghiglione

[ Reply | Forward ]

anything on the lams.log?

Posted by Ernie Ghiglione

By: Dave Bauer

[ Reply | Forward ]

Just the lesson_id 0 errors but nothing to really indicate what was actually causing the error in the first place. Usually I think that occurs because of a timout in Moodle connecting to get the lesson information.

Posted by Dave Bauer

By: Jun-Dir Liew

[ Reply | Forward ]

We fixed a timeout problem with lesson creation recently - there's an updated version of the lamstwo module.

http://wiki.lamsfoundation.org/display/lamsdocs/Moodle#Moodle-LatestChanges

Posted by Jun-Dir Liew

By: Muesser Cemal Nat

[ Reply | Forward ]

Hi,

Few months ago I got the same problem and fixed it by following your changes in /lamstwo/lib.php file.

Recently, I have created much longer lesson in LAMS and tried to added to Moodle as a lesson but I got the same error. Obviously, I can add short lessons but not this long one.

Can you suggest me any way to do this please.

Thank you,
Muesser (University of Greenwich)

Posted by Muesser Cemal Nat

By: Jun-Dir Liew

[ Reply | Forward ]

Hi Muesser,

I guess you're referring to the fix in here, http://bugs.lamsfoundation.org/browse/LDEV-2086? That should have addressed the timeout issue, unless the default in soap library of the Moodle version you're using has somehow changed.

Are there any errors in the lams logs? What does the error text in Moodle say? Is the lesson created on the LAMS side? You can check that last one by logging in as the user in LAMS (hint: first login as sysadmin in LAMS then use 'find user' to find their account and login as them).

Posted by Jun-Dir Liew

By: Muesser Cemal Nat

[ Reply | Forward ]

Hi,

Thank you for your quick response.

Error on Moodle side: lamstwo_get_lesson: HTTP Error: socket read of headers timed out

Error in LAMS log: 2010-02-09 17:15:14,200 [http-0.0.0.0-8080-2:] ERROR org.lamsfoundation.lams.tool.mc.service.McServicePOJO - mcSession does not exist yet: 1527

I am admin and I created the lesson in LAMS.

In fact this is exactly the same error that I got before this fix (http://bugs.lamsfoundation.org/browse/LDEV-2086?).

Moddle's verison is 1.9.4+ and nusoap.php has the following code regarding conection timeout(has not been changed!):

function connect($connection_timeout=0,$response_timeout=30){
// For PHP 4.3 with OpenSSL, change https scheme to ssl, then treat like
// "regular" socket.
// TODO: disabled for now because OpenSSL must be *compiled* in (not just
// loaded), and until PHP5 stream_get_wrappers is not available.
// if ($this->scheme == 'https') {
// if (version_compare(phpversion(), '4.3.0') >= 0) {
// if (extension_loaded('openssl')) {
// $this->scheme = 'ssl';
// $this->debug('Using SSL over OpenSSL');
// }
// }
// }

Posted by Muesser Cemal Nat

By: Jun-Dir Liew

[ Reply | Forward ]

Perhaps we need to increase the 30 second response timeout as a workaround. In moodle/mod/lamstwo/lib.php, can you add two arguments to the soap_client constructor?

In the function 'lamstwo_get_soap_client', make the line that says

$s = new soap_client($wsdl,true,false,false,false,false);

into

$s = new soap_client($wsdl,true,false,false,false,false,0,0);

and we'll see if setting the response timeout to unlimited (0) works for you.

Thanks,

Posted by Jun-Dir Liew

By: Muesser Cemal Nat

[ Reply | Forward ]

As suggested in the latest fix (http://bugs.lamsfoundation.org/browse/LDEV-2086?) I was changed the following line;

$s = new soap_client($wsdl,true,false,false,false,false,3,3);

to

$s = new soap_client($wsdl,true,false,false,false,false,5,5); based on the fix.

But now I removed numbers and made it;
$s = new soap_client($wsdl,true,false,false,false,false);

and it works now :)

Thank you very much,

Posted by Muesser Cemal Nat

By: Muesser Cemal Nat

[ Reply | Forward ]

Hi,

it's me again and I am having the same problem. Because this time my lesson's size is bigger.

I tried all possibilities above but none of them worked :(

Can you suggest me any other solution? Or if you know can I add it manually?

Thank you,
Muesser

Posted by Muesser Cemal Nat

By: Jun-Dir Liew

[ Reply | Forward ]

Try increasing the value for 'default_socket_timeout' in your php.ini. There is another call using the PHP function file_get_contents when you add a lesson, which calls a LAMS URL - but it isn't a soap call like the add lesson call itself.

Posted by Jun-Dir Liew

By: Muesser Cemal Nat

[ Reply | Forward ]

Hi,

Thanks for your reply.

I solved the problem by increasing the timeout and response_timeout values in nusoap.php.

Regards,
Muesser

Posted by Muesser Cemal Nat