One-liner bug: exception raised due to omitted send_error() argument

[jgottula]

I've seen this error in my system log a number of times:

wsdd[20597]: ----------------------------------------
wsdd[20597]: Exception occurred during processing of request from ('172.24.0.4', 60641)
wsdd[20597]: Traceback (most recent call last):
wsdd[20597]:   File "/usr/lib/python3.9/socketserver.py", line 316, in _handle_request_noblock
wsdd[20597]:     self.process_request(request, client_address)
wsdd[20597]:   File "/usr/lib/python3.9/socketserver.py", line 347, in process_request
wsdd[20597]:     self.finish_request(request, client_address)
wsdd[20597]:   File "/usr/lib/python3.9/socketserver.py", line 360, in finish_request
wsdd[20597]:     self.RequestHandlerClass(request, client_address, self)
wsdd[20597]:   File "/usr/lib/python3.9/socketserver.py", line 720, in __init__
wsdd[20597]:     self.handle()
wsdd[20597]:   File "/usr/lib/python3.9/http/server.py", line 427, in handle
wsdd[20597]:     self.handle_one_request()
wsdd[20597]:   File "/usr/lib/python3.9/http/server.py", line 415, in handle_one_request
wsdd[20597]:     method()
wsdd[20597]:   File "/usr/bin/wsdd", line 861, in do_POST
wsdd[20597]:     self.send_error()
wsdd[20597]: TypeError: send_error() missing 1 required positional argument: 'code'
wsdd[20597]: ----------------------------------------

Looks like it comes from the self.path check at the start of WSDHttpRequestHandler.do_POST: https://github.com/christgau/wsdd/blob/e5307bd6c1796c33fb81bdad088fa71e56ed4870/src/wsdd.py#L868-L886 And the problem appears to be that http.server.BaseHTTPRequestHandler.send_error requires an actual value for its code argument (there is no default argument value).

Looks like it ought to be a quick and easy fix.

Thanks!

[jgottula]

Incidentally, this particular case came up while port scanning the system with nmap; and nmap probably sent some garbage that made the program run into this particular situation (which is presumably a rare enough case that no one else has run into it often enough to bother reporting a bug I guess).

Anyway, nmap aside, I'm pretty sure I've seen some sort of wsdd exceptions come up in my system log before, and I'm pretty sure they may have been the same thing. Not 100% sure though. (Will see if I can find anything digging around in my older logs...)

[jgottula]

Will see if I can find anything digging around in my older logs...

Okay, so, upon further review of some of my older crustier logs (involving versions 0.5, 0.6.1, 0.6.2):

• There were a few exceptions here and there from the handle_deleted_address bug that's since been fixed in 453625f.
• There are some scattered OSError: [Errno 99] Cannot assign requested address in socket.bind from time to time, which I'm reasonably certain aren't the program's fault in any direct sense.
• And then the stuff that I was actually remembering being bothered by, was in fact a bunch of WARNING: invalid resolve request: address (...) does not match own one (...) log lines that I was seeing on many days, multiple times per day (often packed into relatively short periods of time, often at 10-minute intervals; the worst case was a string of 32 in the space of 6 hours). But, that log spam situation seems to have only occurred after updating to 0.6.1, and before updating to 0.6.2. So either there was an 0.6.1-specific bug that was causing that, or else there might have been something legitimately going on that just happened to took advantage of the coincidence/correlation between when I do package updates and when I reboot my reasonably-long-uptime systems. In any case, the log spam thing hasn't been a problem at all on 0.6.2+.

And as for the actual case involved in this issue report, where control flow reaches the call to send_error with no arguments, I've only really seen that a few times, and it seems likely that it's probably only ever occurred when running nmap port scans. So, there's that. 🤷‍♂️

[christgau]

Thanks for your extensive analysis.

• There were a few exceptions here and there from the handle_deleted_address bug that's since been fixed in 453625f.

True.

There are some scattered OSError: [Errno 99] Cannot assign requested address in socket.bind from time to time, which I'm reasonably certain aren't the program's fault in any direct sense.

Actually, these ones would be quiet interesting. Maybe you could share the stack trace along with the related log entries. It could still be the case that there is something wrong in the code

And then the stuff that I was actually remembering being bothered by, was in fact a bunch of WARNING: invalid resolve request: address (...) does not match own one (...) [...] In any case, the log spam thing hasn't been a problem at all on 0.6.2+.

Those messages may appear regularly because Windows (or someone) scans the network in intervals - but I'm not sure. Nevertheless, the messages were from the very beginning of the development to learn about the messages. The log level was raised and accidentally landed in 5c184f3149804579932c0ce860e0ed35c724d121 which was released with with v0.6. It was subsequently lowered in cfb44b4044de519fa4aecc3ce5b077bdf8e2ba71 (released with v0.6.2).

Concerning the actual single line bug, I will make a fix...