http logging doesn't seem complete, even w/ -l debug

[mindsong]

Hi there!

Building from the current master (as of this note's timestamp)
Linux xxx.net 4.19.0-14-amd64 #1 SMP Debian 4.19.171-2 (2021-01-30) x86_64 GNU/Linux

The build worked fine, new package was created and installed.

merecat -V
2.32-rc4

Seems to operate well enough from a browser's view with a minimal port-80 initial test install, except for the traffic logging only seems to show errors like 304 and 404 best I can tell, even when started with

merecat -n -f /etc/merecat.conf -l debug

(all messages to stdout, right?)

with /etc/merecat.conf containing only:

username = www-data
directory = /var/www

Your default merecat webpage content is in /var/www and displays correctly, but the only logging I can see is the process start-up info, the http 404s and the 304s - no 200s.

Further (another bug report?) the man page indicates CLI -r and -d options, neither of which works or appears in the merecat -h usage message, as well as some of the other merecat(8) listed options (still on the todo list?)

Lastly, why is it that the newly built deb package that builds from my updated/cloned repo indicates install files with modify dates of "July 7, 2020" on all of the installed files? The 'dpkg-deb --contents' of the new deb file shows the same. Odd that, even after a "make distclean", ./autoconf.sh, ./configure, make package sequence, the resulting installed files in /usr/sbin/merecat are dated July 7, 2020. Is there a forced date in the package build rules (I'm not too savvy about pkg building)?

But thanks for keeping this little gem alive (I've been using thttpd for years now, but it's time for me to upgrade..., and your updates tie it all up very nicely - ssl, etc.)

I hope this info helps, and I can test further if it will help.

cheers,
mindsong

[troglobit]

It has been many years since I started patching up this fork, so I don't remember all the design decisions I made, but this project is not thttpd, so you cannot infer any behavior it had on this project. Also, the master branch is unreleased and still very much under development. The issues you mention about .deb package and out-of-sync command line options are not something I'll go into detail on, but I'd say normal state for an in-progress project. There's a lot of bigger issues to address before turning to fix them. Meanwhile, there are released versions (with lot less features) that I recommend to anyone who want to use this project for now.

[mindsong]

Hello Joachim (troglobit),

Thanks for the reply, and thanks for keeping this handy tool alive.

I appreciate that your make-over of the original thttp project is ongoing and quite substantial, if not almost a rewrite. I'm also very pleased that you have preserved the original "way of thinking" that Mr. Poskanzer designed into the original tool. Bravo for that.

I was hoping that the logging problem was a 'user error', or perhaps it was a runtime or compile-time setting that hasn't been fully detailed in the documentation yet. I can look into the repo and perhaps see if I've missed something. I expect that the logging code is present and mature, simply not enabled due to the way I am running the program.

I'm not at all worried that the deb package mechanism hasn't been updated. It only caught my eye when the file date in /usr/sbin was 2 years old and I had just built and installed it - that was unexpected, and made me wonder if I was doing what I believed I was doing. I'm glad to know that it's not unexpected at this point.

I have a great understanding of 'works in progress' that don't claim to be complete (current/master branches), but are treated as though they are complete anyway - look at the piles of projects on my desk for verification of that! :). My feedback is intended to help identify user-problems, or program issues before they become releases!

As mentioned before, thanks for your continued work this wonderful little tool. Perhaps I could help with some of the more peripheral updates to the codebase - e.g. documentation and examples of usage if that would be helpful. I will peruse the repo before I make promises that may be over my head!

best, and thanks for the reply,
--ms

[stappersg]

I also miss 200 OK in logging, same as in original report of this issue.

[Keisial]

It's not just a matter of logging level. Even running at debug (they are sent with info), they usually are not logged (occasionally they do, though).

After quite some debugging, I found the following:

• handle_read calls httpd_start_reques (src/merecat.c:741)
• httpd_start_request (src/libhttpd.c:4842) maps the file
• ...and sets the headers to send (send_mime call at 4854)
• finally handle_read changes the fdwatch from reading to writing
• then handle_send is triggered
• handle_send calls directly the low-level httpd_write / httpd_writev
• typically, it will do a writev with all the headers and the whole file contents, so at 974 we go through the "Nope, we wrote the full headers, so adjust accordingly." and set hc->responselen = 0
• after fully sending the file, we call finish_connection(), which then calls httpd_send_response()
• if there is a pending response (hc->responselen > 0), httpd_send_response() makes a log entry and send the pending bytes
  Note that make_log_entry() is only called from httpd_send_response() and, other than error pages or directory listings, httpd_send_response() is only called from finish_connection()

The fix seems to be to move up the make_log_entry() call so it is called unconditionlly

However, this causes a spurious log entry of "UNKNOWN UNKNOWN", as finish_connection gets called twice on keep-alives (I'm only seeing it with ssl, perhaps for a normal socket I am too slow).

Keep-alive support in merecat is... weird.

On the one hand, it claims there's no Keep-alive support (libhttpd.c:2942), on the other hand, it replies with Connection: keep-alive, and clear_connection() actually resets the fd so that it could take a new one. If we pipeline two requests, the second one even gets parsed and shows correctly in the log. But the file is not sent!

We could guard make_log_entry() with something else (hc->status != 0, hc->bytes_sent != 0), but I think we do want that message for a new connection which is immediately closed. It's only for a lingering one that we should skip it.

[troglobit]

...
Keep-alive support in merecat is... weird.
...

You know, I stopped reading somewhere around this comment. As most people I skim through at first, and this one caught my eye. Not sure what you're going for, but seeing as we are not familiar @Keisial, maybe a more humble attitude is a good starting point at least.

As you've probably realized by now, this project of mine is on pause. I took quite a lot of flak for trying to modernize and drag thttpd into the future. So as soon as I had a working setup for me, I've taken a back seat to it and left it alone for a few years because I'm just a single person and cannot handle the expectations of everyone taking an interest in this project. At this stage "it works for me", is my stance, so you need to actually contribute to positive and logical changes if you want to "drag" it any further.

Please understand this, I have no interest in guiding people or discussing changes to this project. As this would not benefit me the slightest. This is not anything new to #opensource projects in general, I'm just being extremely honest. To make any dent in this stance, please post razor sharp¹ PRs instead of endless discussions ("talking is cheap on the Internet"). I'm all for changes that lift the project in the direction we all want to see it go, and if this happens we might even see me back at working on this, making releases!

Footnotes

1. as in the Linux kernel sense. Any PR changes/addresses a single area, with each commit being a logical and isolated change that can be run/tested and evaluated on its own. This is a tedious process to some, but has proven to be the only way to gain trust and build change over time. ↩

[Keisial]

Hello @troglobit

I'm sorry you took it that way. That line wasn't meant as a critic to you, your code, or any of the other contributors.

I think I could summarise it as "I'm not even sure if keep-alive is expected to work or not". I tried to explain it in the following paragraph.

I'm perfectly ok with you having little time for this project. That's completely understandable. In fact, it was great to find that you had advanced thttpd.

I tried quite hard to fix the issue myself before finally giving here a summary (at 6 am!) of what I had discovered so far. I think it is detailed enough to show I'm not here to bash the maintainer. I did go into the code, and make sense of it. But at one point, it seemed worth asking. After all, you surely have a much clearer idea of how it is expected to work, than someone new to the code. I have been figuring out, and I had some expectation with the attempt on just moving up that line, but that didn't really work.

As for how PR go, I should note that while trying to debug this, I did find a trivial bug. For which I created its own separate issue (#52) and pull request fixing it (#53), before leaving the above comment.

I'm happy to collaborate on this bug. But I'm afraid this won't be as a simple fix as the previous.

Kind regards