Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logger - socket exception #428

Open
g7gpr opened this issue Sep 25, 2024 · 11 comments
Open

Logger - socket exception #428

g7gpr opened this issue Sep 25, 2024 · 11 comments
Assignees

Comments

@g7gpr
Copy link
Contributor

g7gpr commented Sep 25, 2024

self.logger.log(self.level, message.strip())

On prerelease Pi4, seeing sporadic messages referring to this line.

2024/09/25 09:52:11-INFO-Logger-line:44 - Socket exception: Connection reset by peer (104)

I don't understand what is happening here, apologies for this not being a very helpful submission.

@Cybis320
Copy link
Contributor

I think the log is doing its job and capturing some sort of error. Any chance you could share the whole log? Is it associated with a video stream disconnect or something?

@g7gpr
Copy link
Contributor Author

g7gpr commented Sep 25, 2024

2024/09/25 09:10:15-INFO-EventMonitor-line:2144 - Next EventMonitor run : 01:40:15 UTC; 30.0 minutes from now
2024/09/25 09:10:15-INFO-EventMonitor-line:2148 - Next Capture start    : 10:38:49 UTC
2024/09/25 09:40:16-INFO-EventMonitor-line:2144 - Next EventMonitor run : 02:10:16 UTC; 30.0 minutes from now
2024/09/25 09:40:16-INFO-EventMonitor-line:2148 - Next Capture start    : 10:38:49 UTC
2024/09/25 09:52:11-INFO-Logger-line:44 - Socket exception: Connection reset by peer (104)
2024/09/25 10:10:18-INFO-EventMonitor-line:2144 - Next EventMonitor run : 02:40:18 UTC; 30.0 minutes from now
2024/09/25 10:10:18-INFO-EventMonitor-line:2148 - Next Capture start    : 10:38:49 UTC
2024/09/25 10:40:20-INFO-EventMonitor-line:2144 - Next EventMonitor run : 03:10:20 UTC; 30.0 minutes from now
2024/09/25 10:40:20-INFO-EventMonitor-line:2148 - Next Capture start    : 10:38:49 UTC

Not capturing at the moment, unfortunately I can't download the whole log at the moment

@Cybis320
Copy link
Contributor

oh, interesting. It's no even capturing...

@Cybis320
Copy link
Contributor

It could be this bit:

def timestampFromNTP(addr='0.us.pool.ntp.org'):
"""
refer https://stackoverflow.com/questions/36500197/how-to-get-time-from-an-ntp-server
Args:
addr: optional, address of ntp server to use
Returns:
[int]: time in seconds since epoch
"""
REF_TIME_1970 = 2208988800 # Reference time
client = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
data = b'\x1b' + 47 * b'\0'
client.sendto(data, (addr, 123))
data, address = client.recvfrom(1024)
if data:
t = struct.unpack('!12I', data)[10]
t -= REF_TIME_1970
return t
else:
return None

Maybe, wrap it in a try-except block and add a timeout?

def timestampFromNTP(addr='0.us.pool.ntp.org'):
    REF_TIME_1970 = 2208988800  # Reference time
    client = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
    
    # Set the socket timeout (e.g., 5 seconds)
    client.settimeout(5)
    
    try:
        data = b'\x1b' + 47 * b'\0'
        client.sendto(data, (addr, 123))
        data, address = client.recvfrom(1024)
        if data:
            t = struct.unpack('!12I', data)[10]
            t -= REF_TIME_1970
            return t
    except socket.error as e:
        print("Socket error: {}".format(e))
        return None
    finally:
        client.close()

@g7gpr
Copy link
Contributor Author

g7gpr commented Sep 25, 2024

Unlikely, that code has no business running at this stage.

@Cybis320
Copy link
Contributor

Yes, you are right. I see that now. Sorry.

Maybe something around her?:

def getEventsfromWebPage(self, testmode=False):

@g7gpr
Copy link
Contributor Author

g7gpr commented Sep 25, 2024

That code executes at the start of an EventMonitor run, which is not yet due.

@Cybis320
Copy link
Contributor

Cybis320 commented Sep 25, 2024

So the error is occurring while the program is in this loop:

while not self.exit.is_set():

Which calls this function:

def getEventsAndCheck(self, start_time, end_time, testmode=False):

Which calls:

def getEventsfromWebPage(self, testmode=False):

Which runs:

web_page = urllib.request.urlopen(self.syscon.event_monitor_webpage).read().decode("utf-8").splitlines()

Maybe warp it in a with and catch socket error?:

 try:
    if sys.version_info[0] < 3:
        with urllib2.urlopen(self.syscon.event_monitor_webpage) as response:
            web_page = response.read().splitlines()
    else:
        with urllib.request.urlopen(self.syscon.event_monitor_webpage) as response:
            web_page = response.read().decode("utf-8").splitlines()
except (socket.error, urllib2.URLError, urllib.error.URLError) as e:
    log.error("Socket or URL error in getEventsfromWebPage: {}".format(e))
    return events
except Exception as e:
    log.error("Unexpected error in getEventsfromWebPage: {}".format(e))
    return events

@g7gpr
Copy link
Contributor Author

g7gpr commented Sep 25, 2024

Error was raised at 09:52:11, that code ran successfully at 09:40:15 and was not scheduled to run again until 10:10:18. Why do you think it is that code that had the exception?

@Cybis320
Copy link
Contributor

A likely cause of the error is that a socket is being opened but not properly closed by the client. If the client fails to close the socket after completing its operation, the server may eventually close the connection after a period of inactivity, which is what the “Connection reset by peer” message suggests. This typically happens when the server forcefully terminates an idle or incomplete connection.

It’s also important to note that there can be a delay between when the socket is opened and when the server closes it. The message may not appear immediately after the socket is opened but rather after the server detects inactivity or hits a timeout, which can occur several minutes later.

It'd be worth trying using a with statement when opening the socket ensures that the connection is properly closed on the client side once the operation is complete.

@Cybis320
Copy link
Contributor

Also, I think the code as it is keeps opening a new socket every 30 minutes without ever closing them.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants