Anonymous | Login | Signup for a new account | 2021-03-02 20:36 CET | ![]() |
My View | View Issues | Change Log | Roadmap | My Account |
View Issue Details [ Jump to Notes ] | [ Issue History ] [ Print ] | ||||||||
ID | Project | Category | View Status | Date Submitted | Last Update | ||||
0000123 | easycwmp | [All Projects] Help | public | 2016-03-18 04:04 | 2016-05-11 13:02 | ||||
Reporter | wonderlive | ||||||||
Assigned To | mohamed.kallel | ||||||||
Priority | high | Severity | minor | Reproducibility | always | ||||
Status | resolved | Resolution | fixed | ||||||
Platform | AT91SAM9 | OS | Linux | OS Version | 2.6.39 | ||||
Summary | 0000123: HTTP SERVER CONNECTION FAILED | ||||||||
Description | 2016-03-18 10:11:50 [easycwmp] NOTICE - external script init config_init_local(55):: easycwmp.@local[0].interface=eth0 config_init_local(65):: easycwmp.@local[0].port=7547 config_init_local(83):: easycwmp.@local[0].ubus_socket=/tmp/ubus.sock config_init_local(71):: easycwmp.@local[0].username=acs config_init_local(77):: easycwmp.@local[0].password=Sct123 config_init_local(94):: easycwmp.@local[0].logging_level=4 config_init_acs(165):: easycwmp.@acs[0].username=acs config_init_acs(190):: easycwmp.@acs[0].periodic_time=0001-01-01T00:00:00Z config_init_acs(196):: easycwmp.@acs[0].http100continue_disable=1 config_init_acs(177):: easycwmp.@acs[0].periodic_enable=1 config_init_acs(171):: easycwmp.@acs[0].password=Sct123 config_init_acs(159):: easycwmp.@acs[0].url=http://192.168.169.108:80/acs [^] config_init_acs(183):: easycwmp.@acs[0].periodic_interval=60 2016-03-18 10:11:51 [easycwmp] NOTICE - init periodic inform: reference time = n/a, interval = 60 2016-03-18 10:11:51 [easycwmp] NOTICE - external: execute update_value_change (null) 2016-03-18 10:11:53 [easycwmp] NOTICE - daemon started 2016-03-18 10:11:53 [easycwmp] NOTICE - external: execute inform device_id 2016-03-18 10:11:53 [easycwmp] NOTICE - external script exit 2016-03-18 10:11:53 [easycwmp] NOTICE - interface eth0 has ip 192.168.169.251 +++ HTTP SERVER CONFIGURATION +++ ip: '192.168.169.251' port: '7547' --- HTTP SERVER CONFIGURATION --- 2016-03-18 10:11:53 [easycwmp] NOTICE - http server initialized 2016-03-18 10:11:53 [easycwmp] NOTICE - entering main loop +++ RECEIVED HTTP REQUEST +++ http_digest_auth_fail_response(335):: http_digest_auth_fail_response: header: Digest realm="realm@easycwmp",qop="auth",nonce="599002c19a8b35fe2970182c51d9a2a20000023f",opaque="328458fab28345ae87ab3210a8513b14eff452a2"--- RECEIVED HTTP REQUEST --- +++ RECEIVED HTTP REQUEST +++ http_digest_auth_check(378):: http_digest_auth_check: header: username="acs", realm="realm@easycwmp", nonce="599002c19a8b35fe2970182c51d9a2a20000023f", uri="/", response="a3b97c6940a45876f571fe01c09e5eb3", qop=auth, nc=00000001, cnonce="981184409bb5d7096782306681f35a08", opaque="328458fab28345ae87ab3210a8513b14eff452a2" --- RECEIVED HTTP REQUEST --- +++ HTTP SERVER CONNECTION FAILED +++ +++ RECEIVED HTTP REQUEST +++ http_digest_auth_fail_response(335):: http_digest_auth_fail_response: header: Digest realm="realm@easycwmp",qop="auth",nonce="6f70de597eb161e72e21e5e65677106d00000267",opaque="328458fab28345ae87ab3210a8513b14eff452a2"--- RECEIVED HTTP REQUEST --- +++ RECEIVED HTTP REQUEST +++ http_digest_auth_check(378):: http_digest_auth_check: header: username="acs", realm="realm@easycwmp", nonce="6f70de597eb161e72e21e5e65677106d00000267", uri="/", response="6f17488506469e6d9625827e283ea2af", qop=auth, nc=00000001, cnonce="e6d291990a740d6d03ea59ce3d984e59", opaque="328458fab28345ae87ab3210a8513b14eff452a2" --- RECEIVED HTTP REQUEST --- +++ HTTP SERVER CONNECTION FAILED +++ | ||||||||
Steps To Reproduce | 1.run easycwmpd 2.acs initiate the connection actively | ||||||||
Additional Information | in http.c,i found this method,but i dont know how the condiction is false. static void http_del_client(struct uloop_process *uproc, int ret) { wait(0); FREE(uproc); /* child terminated ; check return code */ if (WIFEXITED(ret) && WEXITSTATUS(ret) == 0) { DDF("+++ HTTP SERVER CONNECTION SUCCESS +++\n"); log_message(NAME, L_NOTICE, "acs initiated connection\n"); cwmp_connection_request(EVENT_CONNECTION_REQUEST); } else { DDF("+++ HTTP SERVER CONNECTION FAILED +++\n"); } } | ||||||||
Tags | No tags attached. | ||||||||
Attached Files | ![]() ![]() ![]() | ||||||||
![]() |
|
(0000408) mohamed.kallel (manager) 2016-03-18 23:17 |
try to remove the FREE(uproc); in the line 299 done_child: fclose(fp); FREE(uproc); //<============== remove this line DDF("--- RECEIVED HTTP REQUEST ---\n"); exit(status); } and tes if your problem is fixed. Please let me know about the result |
(0000409) wonderlive (reporter) 2016-03-21 02:26 |
hello mohamed.kallel, i remove the line which you told me,and it seems not fixed.i print out the value of 'ret' and 'status' in the following,would it help? +++ RECEIVED HTTP REQUEST +++ http_digest_auth_check(378):: http_digest_auth_check: header: username="acs", realm="realm@easycwmp", nonce="a852e1b405e404976c784bb1009745c90000011e", uri="/", response="b3ac3973abf96a1f86b13f8611eb088c", qop=auth, nc=00000001, cnonce="3d715b89c264584f49a72e8330cf4f7d", opaque="328458fab28345ae87ab3210a8513b14eff452a2 " --- RECEIVED HTTP REQUEST ---status 0 --- http_del_client ---ret 3328 |
(0000411) okraits (reporter) 2016-04-03 12:15 |
I think i am experiencing the same issue, at least it's the same error message "HTTP SERVER CONNECTION FAILED" and thus same line of code. I was testing the reliability of connection requests sent from GenieACS to easycwmp and i noticed that in quite a few cases easycwmp simply didn't initiate the requested connection and i didn't find a reason why. I already discussed this topic on the GenieACS mailinglist and the developer thinks it's an easycwmp issue: http://lists.genieacs.com/pipermail/users/2016-March/000677.html [^] |
(0000412) okraits (reporter) 2016-04-03 12:18 |
BTW, i got the same return value as wonderlive. If needed, i can provide easycwmp debug logs and a tcp dump. |
(0000413) mohamed.kallel (manager) 2016-04-04 11:59 |
Lokks like a bug. I have to investigate more in order to confirm it. Sorry, I can not do it right now since I m taken by other projects. I will let you know when I will fix it |
(0000437) mohamed.kallel (manager) 2016-05-04 15:46 |
It's not reporduced for me. Could you add more debug message inorder to follow the reason. Please add the following debug line in the http_new_client() function: else if (auth_digest = strstr(buffer, "Authorization: Digest ")) { if (http_digest_auth_check("GET", "/", auth_digest + strlen("Authorization: Digest "), REALM, username, password, 300) == MHD_YES) auth_status = 1; else auth_status = 0; } DDF("--- MORE DEBUG(1) auth_status = %d ---\n", auth_status); //<---- Add this line |
(0000438) mohamed.kallel (manager) 2016-05-04 15:53 |
What's your linux system? |
(0000439) mohamed.kallel (manager) 2016-05-04 15:57 |
Please try to remove the FREE(uproc); in the done_child: label done_child: fclose(fp); FREE(uproc); //<---- remove this line DDF("--- RECEIVED HTTP REQUEST ---\n"); exit(status); and remove also the FREE(uproc); from the http_del_client() function http_del_client(struct uloop_process *uproc, int ret) { wait(0); FREE(uproc); //<------ remove this line /* child terminated ; check return code */ And then check if your problem is reproduced |
(0000442) okraits (reporter) 2016-05-09 14:45 |
+++ RECEIVED EMPTY HTTP RESPONSE +++ +++ RECEIVED HTTP REQUEST +++ --- MORE DEBUG(1) auth_status = 0 --- --- MORE DEBUG(1) auth_status = 0 --- --- MORE DEBUG(1) auth_status = 0 --- --- MORE DEBUG(1) auth_status = 0 --- http_digest_auth_fail_response(335):: http_digest_auth_fail_response: header: Digest realm="realm@easycwmp",qop="auth",nonce="",opaque=""--- RECEIVED HTTP REQUEST --- +++ RECEIVED HTTP REQUEST +++ --- MORE DEBUG(1) auth_status = 0 --- http_digest_auth_check(378):: http_digest_auth_check: header: username="tdt",realm="realm@easycwmp",nonce="",uri="/",qop=auth,nc=00000001,cnonce="",response="",opaque="" --- MORE DEBUG(1) auth_status = 1 --- --- MORE DEBUG(1) auth_status = 1 --- --- MORE DEBUG(1) auth_status = 1 --- --- MORE DEBUG(1) auth_status = 1 --- --- RECEIVED HTTP REQUEST --- +++ HTTP SERVER CONNECTION FAILED +++ |
(0000443) okraits (reporter) 2016-05-09 14:52 edited on: 2016-05-09 14:53 |
I commented out the FREE calls you mentioned and the issue still occurs. I run easycwmp on OpenWRT chaos calmer. |
(0000444) mohamed.kallel (manager) 2016-05-09 15:48 |
This is wierd, I use also OpenWRT chaos calmer. And I did not get a such behaviour. Could you provide to me a remote access to your equipment for tests. And also the make config to build the package according to your hardware |
(0000445) mohamed.kallel (manager) 2016-05-09 17:44 |
does the problem always reproduced? Or it's rarely reproduced? |
(0000446) okraits (reporter) 2016-05-10 08:45 |
The problem occurs with varying intensity. With a script, i create every 10 seconds a task in GenieACS which asks for a connection request to set a parameter. Here's my debugging output of the GenieACS REST interface: 10 May 08:27:37 - processed 10 May 08:27:48 - processed 10 May 08:27:59 - processed 10 May 08:28:10 - processed 10 May 08:28:23 - processed 10 May 08:28:38 - queued 10 May 08:28:49 - processed 10 May 08:29:03 - queued 10 May 08:29:17 - queued 10 May 08:29:28 - processed 10 May 08:29:39 - processed 10 May 08:29:53 - queued 10 May 08:30:04 - processed 10 May 08:30:15 - processed 10 May 08:30:26 - processed 10 May 08:30:37 - processed 10 May 08:30:51 - queued 10 May 08:31:05 - queued 10 May 08:31:16 - processed 10 May 08:31:31 - queued 10 May 08:31:42 - processed 10 May 08:31:56 - queued 10 May 08:32:07 - processed 10 May 08:32:21 - queued 10 May 08:32:32 - processed 10 May 08:32:43 - processed 10 May 08:32:54 - processed 10 May 08:33:08 - queued 10 May 08:33:22 - queued 10 May 08:33:36 - queued 10 May 08:33:47 - processed 10 May 08:33:58 - processed All lines with "queued" are the cases in which the problem occurs. |
(0000447) okraits (reporter) 2016-05-10 08:50 |
I can provide you remote access to the CPE. Could you please send me your public SSH key? |
(0000448) mohamed.kallel (manager) 2016-05-10 10:20 |
public key attached |
(0000449) mohamed.kallel (manager) 2016-05-10 10:25 |
what you get when you make Connection Request with your browser (FirFox, Chrome...). Do you get the same error? You can make Connection Request from your browser with the URL: http://<address [^] of your router>:7547 |
(0000450) okraits (reporter) 2016-05-10 10:51 |
The error doesn't occur when i connect to easycwmp with a browser. Can you please give me your mail address so i can send you the connection details for the CPE? |
(0000451) mohamed.kallel (manager) 2016-05-10 11:14 |
my email address is in the headers of the source file of easycwmp |
(0000452) mohamed.kallel (manager) 2016-05-10 11:16 |
could you remove the following line too and retry http_del_client(struct uloop_process *uproc, int ret) { wait(0); //<------ remove this line FREE(uproc); //<------ remove this line /* child terminated ; check return code */ |
(0000453) okraits (reporter) 2016-05-10 12:50 edited on: 2016-05-10 12:54 |
I removed the comments in front of the FREE calls and commented out the wait call in http_del_client(). THe problem didn't occur then. I tried for > 30 min in 10 second intervals as i mentioned above. Should i send you the connection details for the CPE so you can do tests on it? |
(0000454) mohamed.kallel (manager) 2016-05-10 13:02 |
OK, so the problem is solved when you removed the wait(0) ?! So as summary to fix the problem you have to remove the following 2 lines: 1) done_child: fclose(fp); FREE(uproc); //<============== remove this line DDF("--- RECEIVED HTTP REQUEST ---\n"); exit(status); } 2) http_del_client(struct uloop_process *uproc, int ret) { wait(0); //<------ remove this line FREE(uproc); And the problme will be solved. Could you confirm that I will add that in the future deliveries. And Thanks I do not need the Device connection details if the problem is solved |
(0000455) okraits (reporter) 2016-05-10 13:13 |
To fix the issue, you have to remove only the "wait(0);" in http_del_client(). The FREE calls at the done_child: label and in http_del_client() are active again. |
(0000456) mohamed.kallel (manager) 2016-05-10 13:27 |
You have to keep all FREE except this one done_child: fclose(fp); FREE(uproc); //<============== remove this line DDF("--- RECEIVED HTTP REQUEST ---\n"); exit(status); } You have to remove it. It's buggy FREE. It could cause problems. Could you please remove it and test again and provide the result of your test |
(0000457) okraits (reporter) 2016-05-10 13:27 |
But can we safely remove the call of "wait(0);"? We don't wait for the child process to terminate then and the return value is not valid. If yes, then why did that line exist in the first place? |
(0000458) okraits (reporter) 2016-05-10 13:48 |
I removed the FREE call at the done_child: label and the "wait(0);" call in http_del_client() and the problem doesn't occur. For reference i've attached the http.c i'm using and which works. |
(0000459) okraits (reporter) 2016-05-10 14:03 |
See also https://github.com/pivasoftware/easycwmp/pull/24. [^] |
(0000460) mohamed.kallel (manager) 2016-05-10 15:00 |
You can safely remove the call of "wait(0);". It's a typo from old versions. in fact the wait of child is done by the libubox functions. |
(0000461) mohamed.kallel (manager) 2016-05-10 15:01 |
I merged your pull. Thank you for your contrbution! |
(0000462) okraits (reporter) 2016-05-10 15:04 |
Thank you - you're welcome. |
(0000470) mohamed.kallel (manager) 2016-05-11 13:02 |
fixed in EasyCwmp-1.2.8 |
![]() |
|||
Date Modified | Username | Field | Change |
2016-03-18 04:04 | wonderlive | New Issue | |
2016-03-18 04:04 | wonderlive | File Added: cpe_passive.pcapng | |
2016-03-18 23:17 | mohamed.kallel | Note Added: 0000408 | |
2016-03-21 02:26 | wonderlive | Note Added: 0000409 | |
2016-04-03 12:15 | okraits | Note Added: 0000411 | |
2016-04-03 12:18 | okraits | Note Added: 0000412 | |
2016-04-04 11:59 | mohamed.kallel | Note Added: 0000413 | |
2016-05-04 15:46 | mohamed.kallel | Note Added: 0000437 | |
2016-05-04 15:53 | mohamed.kallel | Note Added: 0000438 | |
2016-05-04 15:57 | mohamed.kallel | Note Added: 0000439 | |
2016-05-09 14:45 | okraits | Note Added: 0000442 | |
2016-05-09 14:52 | okraits | Note Added: 0000443 | |
2016-05-09 14:53 | okraits | Note Edited: 0000443 | View Revisions |
2016-05-09 15:48 | mohamed.kallel | Note Added: 0000444 | |
2016-05-09 17:44 | mohamed.kallel | Note Added: 0000445 | |
2016-05-10 08:45 | okraits | Note Added: 0000446 | |
2016-05-10 08:50 | okraits | Note Added: 0000447 | |
2016-05-10 10:19 | mohamed.kallel | File Added: id_rsa.pub | |
2016-05-10 10:20 | mohamed.kallel | Note Added: 0000448 | |
2016-05-10 10:25 | mohamed.kallel | Note Added: 0000449 | |
2016-05-10 10:51 | okraits | Note Added: 0000450 | |
2016-05-10 11:14 | mohamed.kallel | Note Added: 0000451 | |
2016-05-10 11:16 | mohamed.kallel | Note Added: 0000452 | |
2016-05-10 12:50 | okraits | Note Added: 0000453 | |
2016-05-10 12:54 | okraits | Note Edited: 0000453 | View Revisions |
2016-05-10 13:02 | mohamed.kallel | Note Added: 0000454 | |
2016-05-10 13:13 | okraits | Note Added: 0000455 | |
2016-05-10 13:27 | mohamed.kallel | Note Added: 0000456 | |
2016-05-10 13:27 | okraits | Note Added: 0000457 | |
2016-05-10 13:46 | okraits | File Added: http.c | |
2016-05-10 13:48 | okraits | Note Added: 0000458 | |
2016-05-10 14:03 | okraits | Note Added: 0000459 | |
2016-05-10 15:00 | mohamed.kallel | Note Added: 0000460 | |
2016-05-10 15:01 | mohamed.kallel | Note Added: 0000461 | |
2016-05-10 15:04 | okraits | Note Added: 0000462 | |
2016-05-11 13:02 | mohamed.kallel | Note Added: 0000470 | |
2016-05-11 13:02 | mohamed.kallel | Status | new => resolved |
2016-05-11 13:02 | mohamed.kallel | Resolution | open => fixed |
2016-05-11 13:02 | mohamed.kallel | Assigned To | => mohamed.kallel |
Copyright © 2000 - 2021 MantisBT Team |