[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#236209: marked as done (server dies and does some other weird things)

Your message dated Mon, 11 Dec 2023 18:54:46 +0000
with message-id <[🔎] E1rClQU-0002Nx-41@fasolo.debian.org>
and subject line Bug#1055839: Removed package(s) from unstable
has caused the Debian Bug report #236209,
regarding server dies and does some other weird things
to be marked as done.

This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.

(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact owner@bugs.debian.org
immediately.)


-- 
236209: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=236209
Debian Bug Tracking System
Contact owner@bugs.debian.org with problems
--- Begin Message --- 
Package: dhis-server
Severity: grave

I'm running dhis as a dynamic dns server in my box, it only has two posible
clients, one is a local machine I set up for testing, and the other one is a
machine connected to the internet through modem+ppp, I have not been able to
get the problems using the client connected localy, it only happens after
the ppp (slow connection) machine uses the dns. Both clients are using QRC
keys to autentify themselves using dhis-client 5.2-3.

These are the versions of dhis I'm running on my server:
dhis-dns-engine    5.0-2
dhis-server        5.1-4
dhis-tools-dns     5.0-2
dhis-tools-genkeys 5.0-2

The server is a dual Pentium 200 running Linux kernel 2.4.25 in smp mode.
The distribution is an up to date Sarge.

I have run the server with -D -D -D -D -D and now I have a problem as my
/var gets filled with the logs when it get's stuck like today

This is the log of what has happened today, after the server had been up for
several days with clients working normally:

...
18:00:20: on_parse(): Executing. 
18:01:20: on_parse(): Executing. 
18:02:20: on_parse(): Executing. 
18:03:20: on_parse(): Executing. 
18:04:20: on_parse(): Executing. 
18:05:20: on_parse(): Executing. 
18:06:20: on_parse(): Executing. 
18:06:59: net_read_message(): Message arrived from 62.83.51.27 
18:06:59: do_dgram(): Processing packet [OPCODE=511] started 
18:06:59: do_dgram(): Message is in R5 format 
18:06:59: do_dgram(): ECHO_REQ received. Sending ECHO_ACK. 
18:06:59: net_write_message(): Sending Message to 62.83.51.27 
18:07:02: net_read_message(): Message arrived from 62.83.51.27 
18:07:02: do_dgram(): Processing packet [OPCODE=521] started 
18:07:02: do_dgram(): Message is in R5 format 
18:07:02: do_dgram(): Received AUTH_REQ for 1001 
18:07:02: do_dgram(): Refresh rate is set to 120 
18:07:02: do_dgram(): QRC Authentication. 
18:07:02: do_dgram(): Sending AUTH_SY. 
18:07:02: net_write_message(): Sending Message to 62.83.51.27 
18:07:05: net_read_message(): Message arrived from 62.83.51.27 
18:07:05: do_dgram(): Processing packet [OPCODE=524] started 
18:07:05: do_dgram(): Message is in R5 format 
18:07:05: do_dgram(): Received AUTH_SX. 
18:07:05: do_dgram(): Sending AUTH_ACK. X and X match. 
18:07:05: on_add(): Marking Host 1001 Online 
18:07:05: mark_online() 1001 62.83.51.27 
18:07:05: service_issue_command: Got service list for client. 
18:07:05: service_issue_command: Sending command to 17020 
18:07:05: msg_log(): Logging -> online 1001 [62.83.51.27] 
18:07:05: net_write_message(): Sending Message to 62.83.51.27 
18:07:20: on_parse(): Executing. 
18:08:20: on_parse(): Executing. 
18:09:20: on_parse(): Executing. 
18:09:20: on_parse(): Sending CHECK_REQ to 1001 
18:09:20: net_write_message(): Sending Message to 62.83.51.27 
18:09:22: net_read_message(): Message arrived from 62.83.51.27 
18:09:22: do_dgram(): Processing packet [OPCODE=542] started 
18:09:22: do_dgram(): Message is in R5 format 
18:09:22: do_dgram(): Received CHECK_ACK. 
18:10:20: on_parse(): Executing. 
18:11:20: on_parse(): Executing. 
18:12:20: on_parse(): Executing. 
18:12:20: on_parse(): Sending CHECK_REQ to 1001 
18:12:20: net_write_message(): Sending Message to 62.83.51.27 
18:13:20: on_parse(): Executing. 
18:13:20: on_parse(): Sending CHECK_REQ to 1001 
18:13:20: net_write_message(): Sending Message to 62.83.51.27 
18:14:20: on_parse(): Executing. 
18:14:20: on_parse(): Sending CHECK_REQ to 1001 
18:14:20: net_write_message(): Sending Message to 62.83.51.27 
18:15:20: on_parse(): Executing. 
18:15:20: on_parse(): Sending CHECK_REQ to 1001 
18:15:20: net_write_message(): Sending Message to 62.83.51.27 
18:15:27: net_read_message(): Message arrived from 62.83.54.134 
18:15:27: do_dgram(): Processing packet [OPCODE=511] started 
18:15:27: do_dgram(): Message is in R5 format 
18:15:27: do_dgram(): ECHO_REQ received. Sending ECHO_ACK. 
18:15:27: net_write_message(): Sending Message to 62.83.54.134 
18:15:31: net_read_message(): Message arrived from 62.83.54.134 
18:15:31: do_dgram(): Processing packet [OPCODE=521] started 
18:15:31: do_dgram(): Message is in R5 format 
18:15:31: do_dgram(): Received AUTH_REQ for 1001 
18:15:31: do_dgram(): Refresh rate is set to 120 
18:15:31: do_dgram(): QRC Authentication. 
18:15:31: do_dgram(): Sending AUTH_SY. 
18:15:31: net_write_message(): Sending Message to 62.83.54.134 
18:15:33: net_read_message(): Message arrived from 62.83.54.134 
18:15:33: do_dgram(): Processing packet [OPCODE=524] started 
18:15:33: do_dgram(): Message is in R5 format 
18:15:33: do_dgram(): Received AUTH_SX. 
18:15:33: do_dgram(): Sending AUTH_ACK. X and X match. 
18:15:33: on_add(): Updating R3 host 1001  
18:15:33: mark_update() 1001 62.83.54.134 
18:15:33: service_issue_command: Got service list for client. 
18:15:33: service_issue_command: Sending command to 17020 
18:15:33: msg_log(): Logging -> update 1001 [62.83.54.134] 
18:15:33: net_write_message(): Sending Message to 62.83.54.134 
18:16:20: on_parse(): Executing. 
18:17:20: on_parse(): Executing. 
18:18:20: on_parse(): Executing. 
18:18:20: on_parse(): Sending CHECK_REQ to 1001 
18:18:20: net_write_message(): Sending Message to 62.83.54.134 
18:18:23: net_read_message(): Message arrived from 62.83.54.134 
18:18:23: do_dgram(): Processing packet [OPCODE=542] started 
18:18:23: do_dgram(): Message is in R5 format 
18:18:23: do_dgram(): Received CHECK_ACK. 
18:19:20: on_parse(): Executing. 
18:20:20: on_parse(): Executing. 
18:21:20: on_parse(): Executing. 
18:21:20: on_parse(): Sending CHECK_REQ to 1001 
18:21:20: net_write_message(): Sending Message to 62.83.54.134 
18:21:22: net_read_message(): Message arrived from 62.83.54.134 
18:21:22: do_dgram(): Processing packet [OPCODE=542] started 
18:21:22: do_dgram(): Message is in R5 format 
18:21:22: do_dgram(): Received CHECK_ACK. 
18:22:20: on_parse(): Executing. 
18:23:20: on_parse(): Executing. 
18:24:19: on_parse(): Executing. 
18:24:19: on_parse(): Sending CHECK_REQ to 1001 
18:24:19: net_write_message(): Sending Message to 62.83.54.134 
18:24:30: net_read_message(): Message arrived from 62.83.54.134 
18:24:30: do_dgram(): Processing packet [OPCODE=542] started 
18:24:30: do_dgram(): Message is in R5 format 
18:24:30: do_dgram(): Received CHECK_ACK. 
18:25:19: on_parse(): Executing. 
18:26:19: on_parse(): Executing. 
18:27:19: on_parse(): Executing. 
18:27:19: on_parse(): Sending CHECK_REQ to 1001 
18:27:19: net_write_message(): Sending Message to 62.83.54.134 
18:27:28: net_read_message(): Message arrived from 62.83.54.134 
18:27:28: do_dgram(): Processing packet [OPCODE=542] started 
18:27:28: do_dgram(): Message is in R5 format 
18:27:28: do_dgram(): Received CHECK_ACK. 
18:28:19: on_parse(): Executing. 
18:29:19: on_parse(): Executing. 
18:30:13: net_read_message(): Message arrived from 62.83.54.134 
18:30:13: do_dgram(): Processing packet [OPCODE=551] started 
18:30:13: do_dgram(): Message is in R5 format 
18:30:13: do_dgram(): OFFLINE_REQ received 
18:30:13: do_dgram(): Calling on_delete() for 1001 
18:30:13: on_add(): Marking Host 1001 Offline 
18:30:13: mark_offline(): 1001 
18:30:13: service_issue_command: Got service list for client. 
18:30:13: service_issue_command: Sending command to 17020 
18:30:13: msg_log(): Logging -> offline 1001 [62.83.54.134] 
18:30:13: Received child 17020 termination signal 
18:30:13: Restarting service process for dns 
18:30:13: init_services(): Creating process instance 
18:30:13: init_services(): Pipe created R:1 W:2 
18:30:13: init_services(): Parent got child 8839 
18:30:13: init_services(): I am the child 8839 
18:30:13: init_services(): child: /dev/null open on 2 
18:30:13: init_services(): child: read pipe descriptior 1 
18:30:13: init_services(): child: stdin redirected (2) 
18:30:13: init_services(): child: stdout redirected 
18:30:13: Received child 8839 termination signal 
18:30:13: Restarting service process for dns 
18:30:13: init_services(): Creating process instance 
18:30:13: init_services(): Pipe created R:0 W:1 
18:30:13: init_services(): Parent got child 8840 
18:30:13: init_services(): I am the child 8840 
18:30:13: init_services(): child: /dev/null open on 1 
18:30:13: init_services(): child: read pipe descriptior 0 
18:30:13: init_services(): child: stdin redirect failed 
18:30:13: init_services(): child: Bad file descriptor 
18:30:13: Received child 8840 termination signal 
18:30:13: Restarting service process for dns 
18:30:13: init_services(): Creating process instance 
18:30:13: init_services(): Pipe created R:0 W:1 
18:30:13: init_services(): I am the child 8841 
18:30:13: init_services(): child: /dev/null open on 1 
18:30:13: init_services(): Parent got child 8841 
18:30:13: init_services(): child: read pipe descriptior 0 
18:30:13: init_services(): child: stdin redirect failed 
18:30:13: init_services(): child: Bad file descriptor 
18:30:13: Received child 8841 termination signal 
...

This last sequence goes on and on till I restart it or maybe this can lead
to a final dead of the server, I don't know, I had to kill the daemon to
stop logs from filling my /var.

Looking at the logs I can see that the dhisd logged:
Thu Mar  4 18:30:13 2004 : -> offline 1001 [62.83.54.134]
but the same even't didn't appear on the dhis-dns-engine log.

I have disabled logging and restarted the server, then the client came in
and as it was logging in, the server seems to have entered a similar state
as the one above, I got the online message in dhisd.log but not in
dhis-dns-engine.log, there was only one dhisd that was forking all the time
(I could see the main dhisd and sometimes a child that gets defunct), it was
like that for about half an hour, eating up the cpu and then it died.

I hope this helps a bit finding the bug. I don't mind testing patches or
whatever, you tell me.

Regards...

--- End Message ---
--- Begin Message --- 
Version: 5.3-3+rm

Dear submitter,

as the package dhis-server has just been removed from the Debian archive
unstable we hereby close the associated bug reports.  We are sorry
that we couldn't deal with your issue properly.

For details on the removal, please see https://bugs.debian.org/1055839

The version of this package that was in Debian prior to this removal
can still be found using https://snapshot.debian.org/.

Please note that the changes have been done on the master archive and
will not propagate to any mirrors until the next dinstall run at the
earliest.

This message was generated automatically; if you believe that there is
a problem with it please contact the archive administrators by mailing
ftpmaster@ftp-master.debian.org.

Debian distribution maintenance software
pp.
Thorsten Alteholz (the ftpmaster behind the curtain)

--- End Message ---
Reply to: