this is one bad actor

58pushcx [My archiving script broke and this chat didn't get saved.]
All right, let's get started. Hey, Gretchen, you must be keeping an eye out for those alerts. And welcome, Rebecca. Rebecca Aris, hard to parse. All right. So this is, where's my, this is Lobster's. This is Lobster's office hours.

01:24Well, I feel anticipated. Thanks for joining. So let's see. So yeah, here in Lobster's Office Hours, you can ask any kind of questions about the site you want or Just watch as I maintain stuff, and let's take a look at where things are.

02:05There's PRs, there's issues. Oh yeah, the big topic is spam bot slowdown. I don't think I'm likely to...

...36I don't think I'm likely to get to anything else besides Spambot stuff after the PRs. We'll see how it goes.

...50where do i want to start here i should start with the prs to kind of move stuff along there was this fix from chamlus stream regular yeah it's been So the slowdown, it's been going all weekend. I want to run through the PRs and issues first, but the short version is it started, really it started Wednesday night US time, but it got into high gear Friday. And the very short version is they are attempting to post stories, but they're not even logged in. I don't know how they know what our story form looks like, but they are a substantial percentage of our overall traffic. They are almost, depending on the day, they are doubling or tripling our traffic for the day. So they're making multiple requests a second trying to spam us. And the invite system is protecting us, this is the kind of thing we would be dealing with all the time I have already fixed one performance issue along that path but yeah it's like roughly a million hits a day. So Hunter and I, Hunter is 355E3B on the site or GhostUser1984 on these streams. He's a moderator. He also does system stuff. And we spent some time on Saturday playing with Iocane. This one might be interesting. So this was recommended by Technomancy, who's a very experienced site regular. And we took a look at adding it and it just, it's not there for maturity yet. I'm going to avoid summarizing this because there's a lot of points. And the creator of Iocane showed up here in the comments and we had a little bit of a discussion about why Hunter and I weren't confident enough putting it public. So that was that and then there was a. There was a kind of painful PR and I say painful because. A potential contributor tried to. Open to PR for an unwanted feature request that I never noticed hanging out the back of the bug tracker. they thought it was wanted and unfortunately they wasted their time and so this is just this is just painful because they're after this first experience they're really unlikely to come back and contribute to the site again but the short version was this issue 1036 was posted four years ago. I never saw it. We never approved it. The issue tracker says, please don't just post random feature requests here. Please discuss them. It is to avoid exactly this issue of people inventing things that they want changed on the site. So I took another pass through the issues. So if you read the issues, which might literally just be jamless, I don't know that anybody else actually watches the repo that closely. You will see a whole bunch of them have gotten touched in the last couple of days. I did a search for anything that was missing a bug tag or a feature tag or a design tag, and I found call it a dozen issues that were not properly tagged. And a couple of them were things I had never seen before. And so I closed out some things. So you see all of these that say updated two days ago, like this is all me. So a couple of them I assigned to myself because they can really only be done by me. And I guess I should prioritize those. because they are a distraction to any potential contributor. And then what else?

08:12That's about that. That was real frustrating to have someone want to help and not be able to accept it. All right. So then this is open. So that's everything that's changed recently. Let me take a quick spin through and see where things are at.

...52The story is hidden in the front page. Reduce its opacity. I'm checking hidden stories restore its opacity.

09:13Oh, hey, DLAMS. You're talking about the, what is it, fetch URL attributes? Something else?

...53yeah, I need, well, I'm glad that was useful. I had main broken for a minute. Yeah, this bug was mine. Some of the username stuff, I started a test and accidentally published it. I think I was juggling too many things and I accidentally pushed it in breaking state, which is a little frustrating. All right. So this is Any story that's hidden gets that opacity. And then this is FedEmp saying that GitHub is confused about this. What prompted this?

11:02This. Show hidden. Story that's hidden. What's up with this only child? Oh, it's the single story view.

...49Let's grab this URL. This isn't in the notes yet.

12:15Oh, this is an improvement then. All right, so failure, so yeah.

13:18That's it. Caches and.

14:01Let's double check that one. How do I want to check that? I guess blame, yeah. So it's stylesheets application. Let's find the hidden line. That's here. So this is issue 1206. Yeah, where this got added. So let's go find 1206. I really should make a shortcut bookmark.

...55Yeah.

15:27All right, so this one that's that's somebody taken on an issue. Oh, this guy. Yeah, this PR. Is this ready to go? Which ones were replies, but I think I got it. All right. Well, let's this is promising. Let's take a look. So we've looked at this one on stream before. This is bring this up. three lines second level siblings second plus level siblings yeah that's correct this works by finding the top level common subtree then starting two levels below that two right because it wants to start at All right, there's an intermediate level rendered by the views that render the comments thread partial. It has to be accounted for. OK. I really do like how much shorter this gets, so the new selector is.

16:53Find me the top level comments subtree. Yeah, I don't love this way of using not. But I don't immediately know what the top level element is going to be. But it's saying not a nested one. I would rather if I know it's going to be in a body or a div. Yeah, that might be the best we can do on that one. Let's look. Bring up the Rails server here. Is it in a working state? Yes, because I was fighting with stuff earlier. So let's find some nested comments.

17:45Did I put mine? All right. So this is... Yeah, there is a...

...58All right. Comments underscore subtree. So here's the first one. And then here's replies. Where'd this go? Okay. Yeah. That's the whole thing.

18:21And then if we look down at, let's just grab this guy. Yeah. So P. There's a comment, a comment subtree, a comment subtree, yeah. Yeah, so this is repeated a bunch.

...46We could say inside

...56I don't love this inside class. Let's not take a dependency on it. All right, since we're comfortable with has and it's inverse not, I think we're OK with that.

19:40so at least it's widely available or wait what was that selector list argument negation pseudo class this is what we're saying This one does not say. Oh, it's not a pseudo class, though. It's standalone. So it's this CSS3. OK. So it does meet our CSS standard. That's fine.

20:34This is a little bit magic. There's more than a little bit magic, but I think I'll take it. This has been broken for a while. This gets rid of so much complexity. So this HTML is repeated here and here because of this inline partial guy, but

21:14Yeah, the way this had worked was it just passed down. Do comments say that they're replies? I think they do, right? Where's your comment tag? no you have your short id in there as data i thought for a while they had a parent i think with this approach we can get rid of the comment parent tree line

22:26Yeah, so that's how that works is it totally drops that.

...40I wonder if it would be better to tweak the template.

...57because the comment elements could have an attribute that says, hi, I'm a reply and I know it, or hi, I'm top level and I know it. But we don't know it. No, because there's the user thread. So if we pick one of these, let's pick HWJ because he's in the middle. Here, This comment has a parent, but it is effectively the root of this tree. Yeah. So we would have to make this... We'd be going back into adding this complexity back, which I would rather not have to be smart about.

24:03I think this is the best simplification available.

26:32Let's go look at the issue to make sure I'm not. I know it says fix, but this literally doesn't link the issue.

27:02Probably, it sure looks ready. Peter. Must have written that on stream. OK, let's deploy that one, actually. Let's grab this and.

...27You are not. You notice this font size is too large? I'm using the wrong terminal. Let's drop out of this and start a new terminal. There we go.

...49Start that. Rails. Where's my fetch? We'll fetch all the remotes. upstairs deploy we'll get that deploy kicked off in the background okay good so how are we doing here story image preview oh this one yeah so this is a real nice thing for open graph images which is just mastodon right now but will include i mean people can manually link on blue sky but we don't currently have a bot on blue sky someday

28:58looks like it's just the comment from here from this contributor there's no anything to review again yet and i read this comment in my email but the gist of it was we looked at this on i think the last stream and i wanted slightly clearer code and some a code path shifted into a background job but This will be so nice. Because if you link to a story on Mastodon, or just because we don't have the, it's been a couple of years since Twitter existed, but where are we now? Mastodon social posters. If you look at our feed, it's just the same L over and over and over. And it's repeated by, you know, being our profile image, but you know, you're really taking the L when you this feed or you subscribe to it i just think it would be nice to reuse the existing image if there's one that's there this will be such a nice bit of variation all right so then images issues this is a new one to me so like i said if you want to look at here let's get the state equals open out of that url If you look at the issues by recently updated, you can see all the dozen that I went through and closed out and fixed tags on some. I'm not going to go through all of them because there were like a dozen. Some of them are quite old, but let's take a look at the new issue, 1519.

31:14And then the other thing is going to be the spam bot slowdown. And I know that's this 1814. All right. So what's going on here? I haven't read this one. It sounds like a bug though.

...34Suggested change on a submission after a while. Press suggest link again.

...49These two stories were changed from AI to vibe coding.

32:04This sounds like there might be two bugs, because if This user suggesting vibe coding twice. It shouldn't be able to. So the deal with suggesting is if you suggest a change to the title or tags on a story and another user suggests the exact same change to the title or the same changes to the tags, it will be made and it should be logged. And the way I read this description, sounds a little bit like they're saying they suggested a change twice to a single story and it took place so all right let's see that's a pretty bad bug if so

33:24So how do I want to investigate this? Let's check on these individual stories, I think.

...40So I'm going to look at these off stream because the list of suggestions and who suggested what is not public. It's not sensitive. I just kind of don't want to think too hard about that one. So let's SSH to prod. Let's run the DB. Select ID from stories where short ID equals this EKR story.

34:26yeah so we'll go this far on actually if i do it like this you'll see user id but that's not a username and we're pretty good about not leaking user ids so yeah that's that's private enough i think

35:00There is only one suggested tag.

...10Boy, that really implies that one user suggested it twice. What's the...

...31Suggested tags controller. Yeah, now I am going to pull this off stream and say who is doing a. So we'll say post dot star suggested. And then dot star and this is I know the URL in the logs happens before the. EKRAUJ. So that's going to have got to do on.

36:31in the rotated out file so we'll cap that to my grip you know this might not be a post it might be a patch let me drop that verb and just say suggested

37:12Oh, it's not Suggest Dead, it's Suggestion. Okay, so I see three posts to Suggestions Controller and the logs, which are deliberately off stream for this first story. And all of them are suggesting The tag vibe coding. And all three are from... Yeah, all three are from Gustav. Let me double check that there aren't any others in the logs, but this is looking like a couple of bugs.

38:56I didn't check the moderations. Give me one second. I'm also going to look off stream at the moderations. So I'm pulling up the database. And then there's the story ID. Was that one 20,000 number? Because that's about how many we've had. Moderations where story ID. I want to compare the timestamp. There is nothing in the moderation's log for that story.

39:35That's a... This is a painful bug.

40:35is it by

41:10So that's going to be.

...45This is the message I wanted to include.

42:16These are two pretty painful bugs. I think I need to urgently work on them.

...33Yeah.

...44They're probably both the fault of this log moderation. This thing runs as a background hook. Oh, Chambliss, you're right. I remember that. That could have been the exact same thing. Also, hey again, thanks for catching my bug with the memorization. All right, I'm going to start with a test because this is definitely behavior that should never have made it into prod.

43:48blogs tag additions yeah so this is i mean it's a tag replacement this is almost exactly the thing that should have caught this and we got more down here

44:23I think this wants to be a test of the suggestions controller, though. Because this one should be deleting the suggestions of the user before Yeah, so save suggested title for user. Save suggested tags for user. I thought both of those would be. It's first.

45:16I guess I can look at the. Yeah, so this tries to find any suggested titles by the user. And then if it didn't find one, it creates one. And this tries to find the suggested taggings to delete.

46:07Rebecca, yeah. Let's take a quick look at that.

...21So don't need these stories open. Inbox count is inconsistent.

...38Ah, so this one, this one's a little complicated. So it's labeled good first issue because you don't have to know anything about moderation, but yeah. The gist of it is in the notification model, this is kind of a classic Rails hassle.

47:08we have this Boolean on an individual notification for whether it should be displayed or not. And this is high quality, is trying to do, trying to discourage sending people back into Flame Wars. So if the story has been flagged a bunch, if the comment is already gone, if the comment has been flagged a lot, if the user has flagged the person who's replying to them if the user has hidden the story there are all of these conditions where we don't want to send the notification so the record exists in the database because these things can happen at any time like you could get the notification and then the votes could change And the story could be gone or the comment could be gone. Those things can happen after, right? So rather than go and find the notification, it's at the point we go to display it, we check all these booleans and we go, should we display it? So this is, we check this when we're showing the notifications on that screen that lists them when it loops, you know, it like selects out 20 or 25 notifications. But then for each one, it calls, you know, through the chain, it calls should display. And if it shouldn't, it just skips it. So you may see a page with 24 or 23 notifications instead of 25. And I think that's the per page is 25, but I'd have to check the controller. So that all works. That's fine. Except that runs in Ruby. And so the inbox count just looks and says, are there notifications that haven't been read? Because all of this stuff happens on a loaded notification record. It's not a SQL query. So the inbox count is wrong if Any of the unread notifications should not be shown or to reuse language should not be displayed because they are not high quality. Thanks GitHub.

49:53So that's the behavior of this bug.

50:04yeah so this one it's it's tagged good first issue because you don't have to have encyclopedic knowledge of the code base yeah and grave chain you're correct so really and this is complicated by the fact that notification is a polymorphic join. And then these are not just looking at the comment, but the comment it's replying to and the story overall, which makes this a fairly complicated join. Oh yeah, also like tag filters. But I think the fix has to be moving these things up, this high quality thing, moving that up into being an active record scope. Because if it was a scope, then we could compose it onto unread, and the inbox count would be correct.

51:41And that is a big, complicated PR. So Rebecca, I don't immediately recognize your username, and I'm sorry if you've contributed something before, but are you new to the codebase? Are you familiar with Rails? Because if you're not really comfortable with the ActiveRecord query interface, this is a pretty daunting task. that looks really small, like the inbox count is wrong, but then there's this giant join. Yeah, I saw you chatting in IRC earlier today. Okay. Well, if you choose to take this on, you will certainly get a lot of practice with the Active Record Query API.

52:35trying to think if we have anything similar we do a little bit so if you go up to the story table there's a this concept of the base story that is so there's some includes But then the thing that's interesting here is not deleted and mod preload. So not deleted says, if you're a moderator, you see all stories. If you're a regular user, you see the stories that are not deleted or you see the stories that you submitted. And that's so that you like see it on the homepage and you can click in if it was deleted and you can read the mod log message, that kind of thing.

53:38And then there's other stuff like hottest that composes a lot of these queries where, so hottest is the alternate name for the homepage. So we take that base and we say, okay, let's also include stories that are not hidden by the user. Let's also filter any tags that are hidden by the user. Let's also say it has to be positive. Let's also sort it. So this is where that notification scope is going to end up is like lots of filters composed. And I would strongly suggest that if you want to implement this, you start with something like is gone or bad comment that you can see just on the comment model. And just one at a time, move those up to the scope. Or rather than move even, just replicate them. Because you can, this doesn't require a join, this doesn't require anything, you look at a single field. And then this one, you look at two fields. And then this one, you look at, let's join it against the story and look at the story. And then, you know, they get more complicated from there. And the parent command has to be a left outer join because you may not have a parent comment that's this complexity.

55:20Thanks for taking it on. And if you get an hour or two into it and you're like, wow, this is really painful and complicated and I'm going to pick off something smaller. That's totally cool. You are not committed. You know, I am very happy to have contributions. And if you go that one's behind you, beyond you, and you punt on it, or just it stops being interesting and fun, that's okay. So let's go back to this bug. Yeah, first, I want to test for this user suggestion.

56:07say let's grab i don't have a suggested tags test do i that's probably contributing all right so we'll say let's create a story and i think we have

...40Yeah, we always have a tag one and a tag two. So can I create a story? Yeah, I knew there was some little dance I had to do. Let's just grab this.

57:13Tag one isn't going to be... Tag one is going to be a local variable. Yeah, let's do... And then we'll create the user. Then we'll save the suggested tags for user. Bang. which is user, no, it's the new array. So they are going to suggest just tag two. Yeah, some of this code is really inconsistent with what's the route?

58:33So we'll say there's that, and we expect that the story, well, let's story reload.

...58Is it E or N? I never remember this. I get this wrong on like every third stream. Okay, it's E. Okay, so you expected... No, this is a failure to create the test data.

59:317-Eleven, line is set.

01:00:04just get standard back in sync there so why are you mad i gave you an array of tags i mean if i create it just right off it'll have just the tag but i love i really don't like testing against that kind of assumption in the factory yeah so say we create a story it got a relation instead of a tag so if i say 2a oh it's an array that's the issue is i was wrapping it in an array okay that's better Is there a tag names? No. Where's my little sidebar?

01:01:39tag bar function. I don't remember what it's called or what it's bound to. It lists all the methods in here.

...56I thought there was one that would give me a list. And I can obviously map to create the list, but tags was Yeah, I guess I'll just do this then.

01:02:43Okay, well, there's my bug reproduced.

...51That's awful. Oh, God, how many years has it been like that? I don't know the last time I've touched this method. So it should have destroyed the taggings for this user.

01:03:15What went wrong?

...32Nothing went wrong. It thinks it worked.

...45Did the suggested tagging get created without the user ID?

...58No.

01:04:05Didn't happen on the first one, right? So this should be green build. Yeah, OK, so. Something about calling this twice. Come here. So if there aren't any suggested tags.

...56Do I have that blogger somewhere?

01:05:20Got to look at something off stream here. Is it dot piracy? Yeah, there it is. So it's a snippet I've used more than a few times. Let's log all of the queries as they go, because that'll give me a hint, right? We did not get any queries logged, because clear relatable connections is not the method anymore. Hmm. Let's hope I don't have to put this in the test spec. Okay. So there's going to be a bunch of like, here's creating the story.

01:06:28from users, and it creates the links. Then the story is done. Then we insert our user. So this is about line 720 of the test.

01:07:07So we grab tag two, we insert into suggested taggings with the story ID, the tag ID, and the user ID. So that's the first save suggested. And then we're going to go into the next here. So that tries to where suggested tagging's ID is one. Shouldn't that be where user ID equals two? It really should be.

01:08:07Oh, boy. Some old debugging, huh?

...28Then we find tag2 again. And this is missing that. destroy. And then it sure looks like it tried to insert into moderations. So that's my second bug, but not visible here.

01:09:08That is so weird.

...20This isn't like it needs to be self-suggested taggings, right? Because it's, yeah, standard RBL, toss that.

...37You really should have a uniqueness validation.

01:10:05What's it called? Scope. Yeah.

...19Now does the test throw an exception?

...27Unknown validator, scope validator. Oh, I missed the word uniqueness, didn't I? Yeah.

...45Okay, so the validation also failed. Oh boy. Standard rb, what are we mad about? Oh, uniqueness should have a unique index on the database column. Yeah, it should, but you know, one step at a time here, buddy.

01:11:17Boy, I am missing something obvious. Let's try the debugger here.

...37All right, so it's created the story and the user, and this is the first creation. Right, so it's doing account or nothing, all right? And what's user ID? User ID is two. Now we're at the second one. There is one in there. And it's in the database. Does destroy all not do what it sounds like? So there's... You know what's suspicious? We saw this before, is it's doing the query as delete the individual suggested tagging instead of why don't I see my where?

01:12:50So in this case, it was deleted. I wonder if because I'm not reloading the story object, it has cached the relation. But what I want to see is, is it delete all? See, this is the query I expected to see, where the story ID has this and the suggested taggings.

01:13:17Does that do anything to the test?

...24Same bug. And now the deletes both look like I expect them to look.

...55Yeah, and then here's it. And user ID is two. This is my new uniqueness, isn't it? I think so.

01:14:32All right, so this is puzzling because they're both. So this should have always been delete all.

...47That was tags and titles going to be down. Now title just replaces, so it's a slightly different strategy, so.

01:15:05This. This create does not include the user ID.

...56It's just mapping. This maps into a hash. I pass a hash in like this. Does it work? I guess if it's creating the records, let's comment out this for a second.

01:16:38This is the user and then the tag is down here. OK, so I guess that works.

...50It's not. So this create method that takes a hash is not tripping that brand new validation because it doesn't instantiate the records. I guess it goes straight to an insert. That. That doesn't seem right.

01:17:16Let's grab the docs.

...26Yeah, runs validation. Similar to create. Tries to create a new object. Yeah, it's genuinely creating an object. All right, so that intuition was wrong.

...49Yeah, so this is when given an array of hashes.

01:18:01We're giving it an array of hashes. Now we're giving it an, oh no, this is the, Default inspect, if you put an array, you don't see like a bracket comma. I don't think, right? Yeah, you just end up with multiple lines.

...40Is it making tags rather than suggested tags? No, because here on suggested tags, like it calls this new tags, but these are actually new suggested tags because it takes tag and then it maps to a hash and then it calls it on its association. I see the typo.

01:19:22Just making sure I didn't change behavior there. This isn't some kind of like caching, is it? It shouldn't be. It's not story, it's just itself in that context.

01:20:09Especially because this is happening across requests.

...30right so there was a off stream somebody posted a article from the ibm press releases and we've removed a bunch of press releases from there before i'm gonna go ahead and drop that domain so it's newsroom.ibm.com

01:21:05So...

...50why are both of those empty

01:23:04So it definitely sees two records.

...18I feel like this is going to be really painful where I'm missing something that's really just staring me in the face because could Could this be creating two records the second time through? It shouldn't be able to. Could it be duplicating?

01:24:02This only lists one. Let's say count.

...14no so it makes one the first time through and then the user id 2 has one suggested tagging then it makes one the second time through and then the user id 2 has two suggested taggings except we've deleted them and right here they don't exist

...49Is it?

...55Could suggested taggings have been cache and then this delete happens and it still reads out of the cache?

01:25:07Yes. Now how the fuck does that not fail? oh it doesn't fail in a web request because yeah the second time through the record already exists so some other code path is filling this cache or just referencing this is somehow filling the cache And then we call deleteAll. And Rails doesn't invalidate the cache for the association. So then it creates something. And then down here, it sees both. That doesn't make sense unless

01:26:22Like I have a green test and I don't have a confident understanding of the bug that's a voice a painful situation. I fixed it, but I don't know how I fixed it. So there's new suggested tags they're suggested. it's where I did the reload.

01:27:18What is doing this query and user ID?

...38Why don't I see a query for this?

...51I guess that's this group by why don't I see that query should happen right up above that underscore you message. And I would think that's this, but why is the insert after

01:28:30Let's comment out some of this.

...40I mean, apparently it is.

01:29:30See, look at that. The querying didn't happen right after the querying. It happened up here.

...52I think calling create bang off of the association Because we see the create. And it referred to suggested taggings and just referring to the relation. Filled the cache back in again. And then it inserted.

01:30:24So how are you? See these don't have a. This join table doesn't have a synthetic ID in it, does it?

...40Oh, it does. OK, wait. So let's look at those.

01:31:04See, I wonder if this said suggested taggings.create in order.

...33So we'll create it without touching the association. And now I would expect the query to happen in the right order. Now we've got a failure. Oh, it's not plural.

01:32:06no once again we say create and it does a select is that my new you know it's doing a select one maybe that's my new validation let's copy that out if that's just a comment that out is that just a distraction Yes, that was just a distraction.

...44What is this? I am suspecting that these logs are happening out of order. Like, how is the delete way down here?

01:33:35So when it creates. And then when it's querying for suggestions. Then the delete fires.

...59What? That shouldn't be. Am I accidentally doing multi-threaded programming?

01:34:36That's how you sleep one, is how the real professionals debug multi-threading problems.

...47So somehow the delete is getting delayed. And it's not happening when I expect it to be.

01:35:46So let's look at this stuff and review what's changed.

01:36:04Replace DestroyAll with DeleteAll. We fixed a variable name, and then we didn't use the association to create the record. Because the bug is somehow that this destroy, which is way up here on 874, is firing way down here on 892. Or 891. It was firing before the create, right?

...56So when it said querying for suggestions, then it did the delete.

01:37:06So it's happening here on 891. There is something clever happening there that I don't understand.

...31Some kind of caching deep in the bowels of rails is giving me a hard time. All right, I'm gonna put the bug back for a second. so that I can check the second part of this about moderation. Yeah. So there's that. There's

01:38:32I did find a moderation. That might just be something else, though. So this did create a user. I did create a moderation. Let's go look at that.

01:39:36What if this failed and it swallowed the error?

...47And it would set all of this stuff. And then there could be a validation error and fail to save. And so then the log moderation. No, that happens before save.

01:40:29So we've recreated the first bug, but not the second.

01:41:45What's happening in this Boolean? OK, so. It's not a new record. If we're not editing from suggestion. And.

01:42:10So in this context, it's called editor, but it means moderator or user. I don't know the name for this anti-pattern, but there's a repeated anti-pattern I see in programs where instead of clearly communicating intent, imperatively, like, I want you to log this moderation, I have decided, one part of a program sets a bunch of state like are you editing from suggestion and who is the editor and then another part of the program looks at that exact same state to implicitly make the decision

01:43:15So if we're editing from suggestions, that's true. And it gets flipped to false, and then that becomes false and. So we shouldn't be skipping out of here. Editor equals nil. I'm really suspicious of this line.

01:44:03Then we call mSaveBang.

...18So I'm going to pull up the Telebugs instance off screen. Was there a failure to save a moderation that happened in the last day? And the short answer is no.

01:45:21Hmm.

01:46:13What if it didn't go into this block?

...21Well, then it wouldn't have changed these things, because it does actually change the tags. That's bug one.

...36So it must have gone into this section.

01:47:20I can only guess that that if save failed somehow and swallowed something.

...36Yeah, but it should have been in a transaction so that if the tags failed to save, nothing else happened.

01:48:27I don't have any other ideas here.

...45I've changed the moderation so that it should raise an exception, but I don't know why. Could have failed, so. Wait. Yeah, so now seven. This changed. Log moderation here. Also called save by.

01:49:45Let's go back up to the controller. So when we create these things.

01:50:06They're inappropriate tags.

...17And we have the original story because this has got to be because the rails attributes API didn't yet exist.

...37Yeah, because all this is handled by the Rails Attributes API now.

01:51:14This is a little complicated because it takes the tags the user suggests, it loads them, it runs this filter, and then it drops them back down to strings, and then it passes them into the method that immediately just loads them back up into tags. Oh, I guess tag suggestions.

...48I don't see a path out of this that doesn't call story save.

01:52:04Because what I was really looking for was any kind of difference or condition between Setting the tags and saving the story, such that the tags were saved, but the story wasn't saved. But they're here together. I could wrap this in an explicit transaction.

...51Let's do that.

01:53:50Let's run the full suite. I got that standard RV warning. But I think that's just the warning, not an error, about the lack of indexes. One of the issues that I touched recently was about database consistency gem, which catches those kinds of things. This giant warning, I am Been waiting for months for the new version of standard RB to include a fix for that warning. I was just digging around over the weekend to find that bug. They fixed it, but then it somehow didn't get merged in time for a release last month. I think they do roughly monthly releases.

01:54:42Yeah, this is pretty unsatisfying.

...50Where are we?

01:55:05And then this issue closed.

...29Is there. So we do leave.

...47We do leave these in the database, don't we?

01:56:37This has happened three times. No, this is one story here three times. Let's just look at all the ones for this. Let's go run this on prod, because my local database is a backup of prod, but it's a couple of days old at least.

01:57:16i don't actually need the user id let's cut that part out see i don't believe this because this doesn't include that 120 number that was the one gxn reported For that EKR, this was like 120,000 and something, 600. Not stories. Well, first, mixing up what I want. I want both of these things. First, show me everything.

01:59:10Lots of suggestions. Or did I goof that join?

...34Lots of suggestions. Or one user who leaned on the reload key.

02:00:00Here's the dupe, the six. The rest of these were all suggesting three different tags, so people must have... 116 is a ridiculous number of suggestions.

...35Did it have a different title and everyone suggested the title?

...54Yeah. Because I highlighted, I lost my clipboard.

02:01:27Nothing deletes the old suggested, does it?

...58I don't like this series of mysteries at all.

02:02:33Okay, something is deleting from suggested taggings and suggested titles. Or it's the way those queries were interleaving and running out of order that during execution, yeah, during execution it saw...

...53So GRxN created the vibe coding suggestion and then did it again. And while the saveSuggestedTaggings method was running, it saw two, it applied it, bug one. It failed to note it, bug two, but then that delete happened out of order.

02:03:37Yeah, the delete happened down here.

...51There's no database record of these. I can't go back and create them. The way this bug worked...

02:04:07These suggested taggings don't have a timestamp on them. So I can't even say... Yeah, because the moderation is missing. So I can't compare to figure out, has this happened before? But then the second part of this is, I can't go the other direction from the suggested taggings, can I?

...41Because if these had a created at on them, I could look at the story and say, no, I can't look at the updated at because that gets touched on everything for the markdown rerender.

02:05:10Almost enough to make me implement event modeling. This history is just gone.

02:06:2855, 664. Do not reset the loaded state. That's, yeah, that's pretty much what's happening that I learned about the painful way here.

...49Without scopes, yep. Yep, oh, and the bug is open too.

02:07:01Oh, these are the expected behavior. Oh, no.

...20You know, I guess what's really painful here is that we're doing it on an association. If I had called the model. Like suggested tagging where. I would understand that the association was out of sync, but the fact that I called it on the association.

...47Yeah.

02:08:10How do I refer to it? Was it like rails, rails, pound, 55664? Does that work?

...46Yep.

02:09:48I don't know what to say about that.

02:11:08Thank you.

02:13:46That's insane satisfying. I fixed a bug, but I don't fully feel like I understood the bug. I didn't reproduce the second part of the bug. And then it strikes at... I didn't...

02:15:02DZ, I don't know, if you're still here, I don't know your username on, oh, no, this was chamless, yeah.

...39It's a degraded state. a story we saw story tags thank you i was struggling enough to get this grammar that all right let's just

02:17:51I just can't save.

02:19:22This is for the next program.

02:20:19I'm going to throw this in the chat room because these things that are sensitive.

...32So in the chat room, there are a number of folks, by which I mean the IRC chat room. So that's, where are we? For anybody who doesn't know it, there's an IRC, because we're old, chat room. And there are a number of folks there who read the ModLog. And, you know, there's a couple of folks who look at it once a day. There's a couple of folks who look at it throughout the day. But either way, it is a reasonably popular feedback channel for, hey, that's a weird ModLog entry, or yeah, that got deleted quick, or hmm, I don't think the moderation policy was right based on this ModLog. so i i threw a link to this comment that i just posted into the chat no good nick no is it still here discord so no good nick this is kind of a recurring topic and I finally wrote up a FAQ about this that collected like years of notes on this so IRC I mean at least it's using SSL now but otherwise IRC is not a lot changed in user visible ways since the late 90s and People always compare it to Discord the last couple of years because that is a very popular place for programmers to chat. And so I wrote up these notes on what is it that people like about Discord. And it's things like you get scroll back on join so the channel doesn't look dead unless you join in the 10 seconds before an existing user hits enter. This is... if you don't mute joins and parts and you join the lobsters IRC channel all day long you will see people come in stay for 30 seconds and then leave and I I think some substantial portion of them are folks who are not especially familiar with IRC this is just my hunch and they look at it and they go oh all right well dead chat room broken chat room nothing's here and they leave because No chat room works like IRC and its disposable history now. I mean, maybe a Signal group chat where you don't see the messages before you join? But you don't have, like, public groups on Signal.

02:23:39Oh, I've spent some more time on Discord since I wrote up these notes. One of the hassles with Discord is that it has intrusive upsells in its clients. These go away on paid servers? Absolutely not. No, not at all. I'm on one or two where they have the boosting thing where other people can basically pay your monthly subscription. It has just as many or more ads. Yeah.

02:24:19all right so where are we now god is prod still on fire that bug was way bigger than i thought way longer than i thought make my own irc v2 if i'm going to reinvent a big wheel it's probably going to be writing my own web framework and or writing my own language this block origin oh that's promising with a client mod oh yeah so This one is worth mentioning. Discord really, it's in the notes, but Discord lows third party clients. And I think that extends to mods. I mean, especially because they get spam bots that are mods of their client. They seem to not be banning people for custom style rules in the browser. But in their client, if you tweak their client, they absolutely do look for that and ban the hell out of you. They tend to do it in waves to make it harder for folks to understand what was detected. But yeah, you're playing with fire on that one. You know, when you say native Linux client, I don't know if you were being... There is an Electron app, is my understanding. Whether you count that as native or not, You know, it depends on whether you're Gen X or not.

02:26:24I guess maybe Millennials are iffy.

...35I mean... Oh...

...48Oh, let's not run that on prod. Definitely not installing the... No, there's a package for it. So my guess is that's the Electron app, all packaged up. But I don't know. I use the web version because I'm not a heavy Discord user, and I also don't want to be a heavy Discord user. So keeping it in a browser where I can at least add block some of the nonsense and close the tab and not feel like I'm missing anything. Yeah. Well, ChemList, if you, what are they called? Filter lists in uBlock Origin?

02:27:47Yeah. I bet if you made a filter list, it would be pretty popular. I would add it.

02:28:12Yeah, I mean, what you'd really want to do is write a script right that grabs that repo and transforms it to keep it up to date rather than you having the chore of watching commits on the other hand you actually watch the commits to lobsters which is wonderful oh boy so where are we so i usually stream about three hours and we're at two and a half And that bug was so weird, it chewed up way the heck more time than I expected, even knowing it was a little bit of a weird one just from the description. But I wanted to talk about this one, and I had it on our to-do list. Let's connect back to prod. Yeah, so it's still going. so typically we run at like 10 CPU utilization even during our busy peaks like monday morning it is now monday afternoon us time but like it looks nothing like this this is the spam bot so to recap because i talked about it literally two and a half hours ago You know, I'll throw my region. This is lobsters. Now we're going to ask questions about this site any time. So the hassle we're having is that some very dumb spam bot is slamming the hell out of the site. And it's tail-faction.log and then jq dash c what am i looking for no let's do a grep for stories new pipe jq-c i'm getting good at jq just dealing with this thing what is it request path path i think yeah so here's the spam bot So I jumped through that hoop just in case any actual user loads the stories page.

02:30:40This is a slightly nicer view. All of these, all of these, 100% of these are getting a 302 over to slash login because you cannot load the story form without being logged in. So we are serving these very quickly. There's just so fucking many of them that it's swamping the server. And yesterday, Hunter gave me a big hand investigating this. And we took one thing, one query off the hot path. There was... because there's the novelty logo on the site that shows you how much traffic is there from logged in users. It says traffic, but really it's like a roll up of activity of votes and comments and stories being posted, which means on Monday the logo tends to be bright red and then the rest of the time it tends to be fairly dim. The database read for this logo intensity was actually a significant load on the database. This is just a big fucking annoyance. And so even though we are replying very quickly to them, there are so many of them, they're swamping the web server. Let's double check. The database server shouldn't be working hard. Yeah, so like the database server is fine. It's not swamped. Usually when we have performance issues, we've let in a 1 plus n regression or something is happening that's hitting the database a lot. This is, you know, usually Rails apps get bottlenecked on the database. This one is this irritating fucking spam bot And I don't know what the purpose of it is. It's weird. Like it knows that we have this form, but it never notices that it's not succeeding. And yeah. So side note, in case anyone asks why lobsters has the invite system, it's this, it's this kind of spam. That is, this is one bad actor. If we had open signups, we would see a bad actor on this scale. A new bad actor, probably every week. Like it would be a full-time job for a senior engineer to try and stay ahead of that arms race. And they would lose because the web is too big. You need a lot of help. You'd need external services. You'd need, What was the one that was around for years that WordPress bought? Akismet or others. There are a lot now because spam is a big deal.

02:34:10My guess would be that what's happening with this bot is it's scraping things like these RSS feeds from news sites. strictly to slip in one in a million that's whatever the spam they're getting paid for so they'll bury us in other crap just so that every once in a while they can put in you know the garbage tier spam that we've seen like the best two hotels in some random city call centers in malaysia we've had spam for escort services in various cities but i don't know i'm not going to read through we're literally getting a million of these a day this bot has been around for for ever at least for months because i noticed it I know I saw it earlier this year. Did I see it last year? So typically, it would hit us about 200, 250 times a day. So we didn't notice that traffic. It didn't matter. Now that it's hitting us a million times a day, all right, that matters.

02:35:46wonder if i could shove these up to caddy so hunter and i spent some time tinkering with caddy see the thing about the 302 is it's the temporary redirect and when you succeed at posting to a rails form it 302 redirects you to your posted item or, you know, that's the success. So like we see that, I don't know, model story dev create. No, sorry, controller story dev create.

02:36:34Yeah, so like this is the success flow is you get redirected to go look at the story you just created. So I don't think this dumb fucking bot knows that the 302 it's getting is a failure. Not that I think there's a lot of attention behind it because we're just not big enough to be worth targeting that way. There is a whole side hassle that I looked at logging things like user agent to see if they had something obviously dumb in their user agent string.

02:37:18the interface between rails to rack to puma to caddy is still dictated by the old rfc for cgi so the user's browser headers between caddy and everything else get slammed into environment variables named HTTP underscore and then the uppercase version of whatever header they set so like. We just lose fingerprinting information immediately.

02:38:50Let's try and catch them earlier.

02:39:08Let's grab this. Because I'm going to guess they don't try and set a cookie.

...23And can I filter on a path? Does anybody know caddy offhand? Because what I want to say is if you are doing, they're not posts. Part of what makes them stand out, you see it in my grep here. Actually, here, let's just grep for CNN. Because it seems to eat the CNN feed and post a lot of those. Here let's CAD iPad. So like, I'm not worried. expose a real user ip here all of these are the spam bot but it's always a get oh yeah i mean if i run wcl yeah so it's this is And this action.log is rotated. So wait, where's day U? So it is 2252 UTC. Oh, so just about a full day, right? Ooh, if I had that, yeah, jq-c.timestamp, right? Yeah, so this is one day basically worth is they tried to submit 16,000 of these I mean the site gets a couple of dozen stories a day, so if we search for how many times to somebody load stories new. With. query string. You can get here as a user if you use the bookmark lit. that's why i'm being really deliberate about using jq to filter these things. But yeah, today we have seen 447,316 attempts at spam. But you could give back maybe 10 or 15 of these as actual users. Actually, if I say, they'll be logged in almost always, script-v nobody. Oh yeah. Okay. So maybe, maybe 60 times, this is just like an estimate. So a lot of people use the bookmarklet or that URL. If you use the bookmarklet to bring up the story page, you can immediately see if a story was submitted. Like I do this all the time where I am reading a nice blog post. This isn't my personal browser so i don't have the bookmark clip but and then you know you go in the bookmarks and you say oh submit to lobsters and it goes this was submitted a couple hours ago and just immediately forwards you here so if you are reading a nice technical blog post that's a quick way to get to the lobsters comments people actually do that so i underestimated it's not 10 or 15 it's 60 of those were probably real the other 447 000 260 51 i don't know so let's see if caddy wants to handle it better

02:43:24Okay, so we'll say only method get.

02:45:44So we want to say method get and we want to say path. Wildcards may be used. Does this include query string parameters? Can I say query instead? No, these are query string parameters. So the thing I'm trying to do is say that it has to be looking for, wait, is the login page going to be in the cache?

02:46:54That's every patch page.

02:47:06So let's go look at the story controller. And it has a caches page. We don't want to cache the login page, though, because it's got a form on it. And if we cache it, everybody's going to have the same CRS. f token for that 60 seconds that's bad so logins do have to go all right so let's just i'm trying to think of how to catch these folks and not a user who does the common thing i just described of using the bookmarklet but they don't happen to be logged into lobsters

02:48:02So let's just say path is stories new. And was it query bars? I'm trying to write this as limited as possible. So query empty string matches requests with no parameters. Okay, Q with any value. So I want to say you have to have title equals, you have to have URL equals. Just trying to minimize the false positives here. The other hassle is, because I'm trying to deal with gets, if I wrote something really strict, like, Hey, if you're not logged in and you do this get, well, we're going to consider you part of the spam bot. And we're going to just drop traffic from your IP for 24 hours. Well, then an abuser could say, ah, let me make an image tag that links over there, et cetera. and then real users or regular browsers would be able to get blocked.

02:49:43Yeah. All right. So we can say

02:51:15Do I want to give them back a 403?

...38I don't think they're going to care.

...53Let's say this header should have content type text HTML.

02:52:36Alright, so this is a lot of code to YOLO for something I am not super confident in. On the other hand, it's all very simple code.

02:53:25So let's paste that into prod. And then I'm going to kick prod. So I've got to bring up the Hatchbox web UI to update caddy config, which is inconvenient. Hatchbox, one of its limitations is that it's not really built with the idea of putting your config in source control. making it part of deployment so the way we do that is a little bit of a bolt on all right so that deployed fine where's that tail that's that's over here in the one

02:54:34okay okay that that is really promising well all right so there's one that made it through i don't know why these would make it through but these ones like that are code related hmm Let me pull this off screen and look at the caddy log for a second. So the way the logs are split up, that action log has everything that is a Rails action, and the caddy log is anything it serves. So if I tail-f the caddy log with that grep,

02:55:32Yeah, the Spambot is still going full speed. So I can bring that back up. So here's the tail of the catalog.

...48So it's now handling most of these. So how's the server load? Oh, look, we are in a much happier state. This is high. but it's not 100%.

02:56:13Out of curiosity, now that these are here, I can get at the headaches a little easier. Did these all have...

...29If I say request dot headers dot user agent.

...39Oh, it's not this one. Do they go around the dot or had to deal with this? I think they go. Yeah, let's capitalize. Let's spell correctly.

02:57:01Yeah, so they are just how old is Chrome 125?

...16Very old.

...28Does this actually? And can never tell because every user agent includes everybody. Is this saying it's Safari or is this saying it's Chrome? Or is it just shoving everything in? I don't know if this is Safari 536. Let's see if anybody's talking about this user agent.

02:58:00One hit. Okay, so you think it belongs to Chrome, but it's version 125. Okay, so let's go back to...

...35And now that we know they're using this terrible user agent,

02:59:15What did I do with my dots?

...33Otherwise, it is a fast exact match. I want fast. So let's say when they have the header, User agent, it helps that they do one dumb identifying thing.

03:00:00So let's do that and bounce caddy, which I click off screen for it's updated. All right. So let's go.

...38I don't want to do dash fn. What do I want to do?

...55Let's check the action log to make sure that if you were getting through now, 0 seemed to be getting through now. That's weird. Okay, so some of these are still coming through. But that's even fewer than it was before. And load is just eyeballing, maybe a little bit lower. All right.

03:01:43I'll move that off screen because it's going to have regular users in it. Yeah. I think there's actually two bots. I think there's the big one that we just caught, and I think there's a second one. I wonder if, so I had said the behavior of this bot shifted a couple of days ago from 250 requests a day to a million a day, I wonder if there's still that 250 a day and this million is just an entirely new bot. All right.

03:02:48yeah so here's the caddy log the bot is going strong although my grip is a little wrong and i'm grabbing some things that are people loading actual pages unless unless their bot is like an actual browser and is actually trying to grab all of these assets Oh, they're not grabbing them now. All right, let's grab this stuff back to the caddy file.

03:03:37So I'm going to throw up the last call banner, because I got a rundown. We're over three hours. But this is pretty good. We caught something significant here. I'm going to get rid of this because maybe they're sending like old ass cookies too. Yeah, we can get rid of this.

03:05:02possibly I don't think we're getting a session cookie though I mean I deleted that cookie line just because this header is so significant but yeah all right

...38Oh, I can't even type.

03:06:00Did that math right, did I? So if I look at, because I did see What, a million? Divided by 24 hours divided by 60 minutes divided by 60 seconds gets me 11, yeah. This thing is uneven, so 11 a second.

...46You know, honestly. This is such a weird ass user agent, I could probably throw all of it away, but I'm a little reluctant to.

03:07:02Alright, we'll call that good.

...23That was 1814, right? Yeah.

...53And then let's deploy. And when the deploy is done, I'm going to hit the update caddy. And if the server doesn't immediately fall over because I managed to make a typo, then I'm going to roll up the stream. So this is your last chance to ask questions.

03:08:17Yeah, so ChamList, the thing is, even if we decrypted the session cookie, Well, I think the session is not in the cookie. It's off in the database, but I don't recall off the top of my head how that's configured. It's not dispositive because we still wouldn't be able to tell if the spam bot didn't have this dumb ass user agent, if it rotated realistic user agents. It would be much harder to tell this apart from real user traffic because real users land on this page looking identical and logged out. And we saw it happens, what, at least 60 times a day? So, all right. So yeah, caddy updated fine. Let's go look at the server and make sure it's still not on fire. It's still not on fire. That's good. It's not supposed to be on fire. That's actually fairly high. Alright.

03:09:29But our load average is like 4, not 14. I'll keep tinkering. We'll see how it goes.

...46yeah and you know so even with no queries it is totally possible that I mean, first off, three milliseconds seems high for a, like, check SQLite on disk to see, to pull the traffic intensity, see that you don't have a cookie redirect. Like, three milliseconds is actually a lot of time. But even if that was a more reasonable, like, one, I wonder if we would be hitting GC pauses, because... Those are not going to show up in the duration in our logs because Puma tries to be clever about moving garbage collection pauses between requests. And so just the fact that we're in a GC language, we'd be hitting those. I don't know. In a lot of ways, Ruby is not the language you would write if you were writing for a high performance garbage collected language. And a heroic amount of effort has gone into it over the last 20 years to make it fast for a scripting language. Shamless, I don't know. I know it tries to minimize that, but yeah.

03:11:27the whole thing with puma is like it is pre-forking processes to handle requests and so they live you know between deploys they don't restart automatically i don't think otherwise there might be some like handle a million requests and then just assume you had a memory leak and recycle yourself kind of thing happening but i don't think so off the top of my head so between requests those Puma workers rails. Yeah, still has to like, new up the action controller instance. Because the way it connects, because rails just barf stating everywhere. like with the whole way that views are coupled to action controller via instance variables that is a big object that has to get thrown away every request even though it's a little funny that the controller has to be replaced between requests as opposed to like the template render has to be replaced between requests sure I'm going to roll out. Hopefully the site is going to stay up and performant. I should be back on Monday. No, today is Monday. I should be back on Thursday morning at nine Chicago time to take questions and break things and maintain things.

03:13:25So hope to see you all again on Thursday or just around the site. Take care.