Comment links cause server errors with recent migrations

[ayleph]

Following a comment link (like http://mediagoblin.example.org/u/user/m/my-media/c/1) after applying federation updates results in a server error.

Error - <type 'exceptions.AttributeError'>: 'NoneType' object has no attribute 'comment'
URL: http://photos.technicallyandrew.com/u/andrew/m/belfast-87a3/c/2/
File '/path/to/mediagoblin/lib/python2.7/site-packages/Paste-1.7.5.1-py2.7.egg/paste/exceptions/errormiddleware.py', line 144 in __call__
  app_iter = self.application(environ, sr_checker)
File '/path/to/mediagoblin/mediagoblin/app.py', line 342 in __call__
  return self.call_backend(environ, start_response)
File '/path/to/mediagoblin/lib/python2.7/site-packages/Werkzeug-0.8.3-py2.7.egg/werkzeug/wsgi.py', line 411 in __call__
  return self.app(environ, start_response)
File '/path/to/mediagoblin/mediagoblin/app.py', line 276 in call_backend
  return self._finish_call_backend(request, environ, start_response)
File '/path/to/mediagoblin/mediagoblin/app.py', line 318 in _finish_call_backend
  response = controller(request)
File '/path/to/mediagoblin/mediagoblin/decorators.py', line 47 in wrapper
  return controller(request, *args, **kwargs)
File '/path/to/mediagoblin/mediagoblin/decorators.py', line 210 in wrapper
  return controller(request, media=media, *args, **kwargs)
File '/path/to/mediagoblin/mediagoblin/decorators.py', line 170 in wrapper
  return controller(request, page=page, *args, **kwargs)
File '/path/to/mediagoblin/mediagoblin/user_pages/views.py', line 135 in media_home
  mark_comment_notification_seen(comment_id, request.user)
File '/path/to/mediagoblin/mediagoblin/notifications/__init__.py', line 64 in mark_comment_notification_seen
  comment = Comment.query.get(comment_id).comment()
AttributeError: 'NoneType' object has no attribute 'comment'

[ayleph]

Changing priority as the issue reported in this ticket causes crashes and makes a portion of the interface unusable.

[Jessica Tallon]

I'm not too sure why this is happening but I'll investigate now, hopefully I can get a patch for you today.

[Christopher Allan Webber]

ayleph, I just tried this myself and am not seeing the problem.

Here are the steps I took took:

1. I switched to the v0.8.1 branch, initialized a fresh database, added a comment to an entry.
2. I then switched to master and did a dbupdate.
3. I then went onto the page and clicked the link to the actual entry.

I have not tested this with Postgres however. Ayleph, was this on a Postgresql instance?

[ayleph]

Thanks for looking into this Chris. This is indeed a postgresql instance, and the error does continue to happen (still shows up in my rotating log). If you can't replicate, then it's possible that something went awry in earlier database migrations that's still causing issues for me. Looks like I'll have to dig deeper to find the issue.

[ayleph]

I'm going to remove the "blocker" tag and the milestone since nobody can replicate this issue. But I would like to keep the issue open in case I find something that needs to be addressed.

[Christopher Allan Webber]

Wait, before we remove that milestone, we should make sure that it's not affecting other Postgresql users! We should try reproducing this process with postgresql first; if we screw things up for other Postgres users, that's a bad release!

So let's try reproducing this on Postgres next, and then we'll see if we should lower the priority. :)

[Christopher Allan Webber]

All 0.8.2 tickets are being rolled over to 0.9.0

[Christopher Allan Webber]

I tried this here. I couldn't reproduce it using the same steps I used above, but now I'm noticing that this has to do with notifications... it might not even be related to postgres vs sqlite. In other words, I shouldn't attempt to reproduce this issue using the same user. Will give this a try with 2 different users.

[Christopher Allan Webber]

Hm, I tried reproducing this, and I'm failing to do so, even with Postgres. ayleph, could you produce some steps to reproduce? I'm sure it probably is an issue, but with no way to reproduce it, there's no way to address it before the 0.9.0 release, so I'm removing that milestone for now. Would love to get to the bottom of it though!

[ayleph]

I was just able to reproduce this issue with current master (​062e378) on an instance running sqlite.

Steps to reproduce:

• Create two users (user A and user B).
• Log in as user A. Upload a picture. Log out of user A.
• Log in as user B. Comment on picture from user A. Log out of user B.
• Log in as user A. Click on new comment notification icon next to dropdown arrow. Click on timesince link (says something like "0 minutes ago") next to user B's name.

In this test, the comment link which gives the server error looks like this.

​https://pumpdev.goblinrefuge.com/u/admin/m/columns/c/32/#comment

[ayleph]

If I start messing around with that link and changing the number after c, I get varying results. On this instance, I can change the 32 to any number from 0 to 23, and the page loads. If I change it to anything greater than 23, it gives a server error. This would seem to indicate the comment index isn't being set correctly in the link.

[ayleph]

Dumping the sqlite db shows that the correct comment ID is indeed 32, so my previous idea is debunked.

[ayleph]

It looks like on this particular instance, something happened after comment 24 which causes the comment query to fail.

The specific code which is failing is in mediagoblin/notifications/__init__.py.

def mark_comment_notification_seen(comment_id, user):
    print("DEBUG: comment is %r" % Comment.query.get(comment_id))
    comment = Comment.query.get(comment_id).comment()

The debug print statement (added by me) returns None for comments greater than 23. For comments less than 24, it returns something like <mediagoblin.db.models.Comment object at 0x7f91931e5150>.

The sqlite database excerpt here shows the comments definitely exist.

20|11|2015-11-02 22:51:34.051879|Test comment||http://pumpdev.goblinrefuge.com/api/comment/f489ef9e-d945-481e-8128-3fb8ddb96120/|2015-11-02 22:51:34.051891
21|11|2015-11-02 22:53:06.430691|another test comment||http://pumpdev.goblinrefuge.com/api/comment/56a2e4b8-5238-47d1-afc5-865c28765dbb/|2015-11-02 22:53:06.430703
22|11|2015-11-02 23:02:14.681106|why are these comments not showing up?||http://pumpdev.goblinrefuge.com/api/comment/bf092760-47af-4c9c-a107-8f030ef87005/|2015-11-02 23:02:14.681118
23|11|2015-11-02 23:02:29.357950|lets try doing two in a row?||http://pumpdev.goblinrefuge.com/api/comment/b7a3b621-b7dc-4ad7-a1e1-871545aaad15/|2015-11-02 23:02:29.357962
24|11|2015-11-02 23:03:48.130698|so it seems comments dont show up if i click away too fast||http://pumpdev.goblinrefuge.com/api/comment/7d6eacd7-84e1-4a7a-80e3-139bf5f1a5e2/|2015-11-02 23:03:48.130713
25|5|2015-12-18 03:30:14.330472|test||https://pumpdev.goblinrefuge.com/api/comment/452d35c9-ed57-4055-a89a-b409721daa14/|2015-12-18 03:30:14.330484
26|10|2015-12-18 04:51:26.097513|test comment ||https://pumpdev.goblinrefuge.com/api/comment/d79e1a2d-531f-47d2-b94c-09074338884b/|2015-12-18 04:51:26.097523
27|10|2015-12-18 04:52:37.087098|test comment||https://pumpdev.goblinrefuge.com/api/comment/d60248b1-8d53-4da7-b0ed-52dc397068f5/|2015-12-18 04:52:37.087115
28|10|2015-12-18 04:53:03.020870|why isn't this working??||https://pumpdev.goblinrefuge.com/api/comment/ae4d73ff-1e45-437b-b7c9-1ebcc2a653fa/|2015-12-18 04:53:03.020881
29|10|2015-12-18 06:09:19.024263|comment incoming from Goblinoid!||https://pumpdev.goblinrefuge.com/api/comment/cab133ab-602b-4198-a77c-075e6b8da971/|2015-12-18 06:09:19.024279
30|10|2015-12-18 06:14:31.060412|another comment incoming!||https://pumpdev.goblinrefuge.com/api/comment/4b9f3be8-0542-466e-9519-ff236de8aaf8/|2015-12-18 06:14:31.060436
31|10|2015-12-18 06:16:11.852816|incoming!!!||https://pumpdev.goblinrefuge.com/api/comment/e2e9a3ae-e153-465c-bf01-b1fc3dc29986/|2015-12-18 06:16:11.852879
32|5|2016-02-22 02:55:34.543931|test comment|||2016-02-22 02:55:34.543945

I don't see anything obvious like misaligned columns in the above dump.

[ayleph]

Oh, here's something interesting! The table core__comment_links only has 23 entries.

sqlite> select * from core__comment_links;
1|6|13|2015-10-25 18:51:38.901232
2|19|20|2015-10-25 18:51:38.903586
3|21|22|2015-10-25 18:51:38.905716
4|21|23|2015-10-25 18:51:38.907162
5|21|24|2015-10-25 18:51:38.908971
6|21|26|2015-10-25 18:51:38.910794
7|21|27|2015-10-25 18:51:38.912487
8|21|28|2015-10-25 18:51:38.914034
9|18|29|2015-10-25 18:51:38.915843
10|18|30|2015-10-25 18:51:38.917237
11|21|31|2015-10-25 18:51:38.918661
12|21|32|2015-10-25 18:51:38.920062
13|21|33|2015-10-25 18:51:38.921513
14|21|34|2015-10-25 18:51:38.922919
15|21|35|2015-10-25 18:51:38.926255
16|21|36|2015-10-25 18:51:38.927810
17|21|37|2015-10-25 18:51:38.929365
18|21|38|2015-10-25 18:51:38.930774
19|54|57|2015-11-02 23:02:14.686358
20|54|58|2015-11-02 23:02:29.362211
21|50|59|2015-11-02 23:03:48.137239
22|14|90|2015-12-18 03:30:14.376028
23|99|111|2016-02-22 02:55:34.622969

The 23rd entry here corresponds to the entry I placed on the site today, which received ID 32 in the table core__media_comments (same timestamp).

sqlite> select * from core__media_comments where id=32;
32|5|2016-02-22 02:55:34.543931|test comment|||2016-02-22 02:55:34.543945

It seems that mark_comment_notification_seen is trying to query core__comment_links, but the comment_id being passed to it is from core__media_comments, and they don't match up.

[ayleph]

I don't really understand the connection between core__comment_links and core__media_comments. I see that class Comment is associated with core__comments_links and class TextComment is associated with core__media_comments. It appears that the comment is being created as a TextComment object, but mark_comment_notification_seen is trying to act on a Comment object.

Since I don't understand how things are supposed to work, I'm not sure the right approach here. I've made a change locally which prevents server errors and highlights the comment as expected, but I'm pretty sure it's not the correct solution. The reason I doubt this is correct is because the code I'm removing was added specifically in the ​commit which introduced different comment types.

Here's what I've done, in case it helps point out the root cause.

diff --git a/mediagoblin/notifications/__init__.py b/mediagoblin/notifications/__init__.py
index 8690aae..fa91f63 100644
--- a/mediagoblin/notifications/__init__.py
+++ b/mediagoblin/notifications/__init__.py
@@ -17,7 +17,7 @@
 import logging
 
 from mediagoblin.db.models import Notification, CommentSubscription, User, \
-                                  Comment, GenericModelReference
+                                  TextComment, GenericModelReference
 from mediagoblin.notifications.task import email_notification_task
 from mediagoblin.notifications.tools import generate_comment_message
 
@@ -61,7 +61,10 @@ def mark_notification_seen(notification):
 
 
 def mark_comment_notification_seen(comment_id, user):
-    comment = Comment.query.get(comment_id).comment()
+    comment = TextComment.query.get(comment_id)
     comment_gmr = GenericModelReference.query.filter_by(
         obj_pk=comment.id,
         model_type=comment.__tablename__

[Jessica Tallon]

So, the Comment object is an object that wraps other objects, the Comment creates a link between the thing you are commenting on and the comment object itself. In pump.io comments can be virtually anything, they can be activities, photos, blogs, text, anything more or less, also virtually anything can have comments on them. This requires a major re-working of how comments work, Comment will let anything be the object being commented on and refer to some object (could be a TextComment, could be media, a user, an activity, etc.) as the comment.

core__media_comments is the old name, it's not changed it as it's awkward to do and largely unnecessary, this represents the TextComment. All previous mediagoblin comments are TextComments and anything in the API with the objectType of comment is also a TextCommet.

[ayleph]

Thanks for the comment, but I'm afraid I still don't quite get it. I assume my "fix" above is not the correct fix, even though it seems to do what I expect. Does that mean there's a bug somewhere in assigning comment links to actual comments? Something's definitely not working correctly between core__comment_links and core__media_comments to cause the comment query to not return the correct item.

[Jessica Tallon]

So you're right that the fix you proposed might be a temporary fix as we only currently store TextComments however very soon we will be storing any kind of comment, this will cause your fix to cause the same problem we're seeing except that fix might actually return TextComments which are not for the user and the user might not even have permission to view said comments.

The fix is to ensure the Comment (core__comment_links) entry is being made and use that id in the URLs, this then should look up the comments and dereference the comment it's pointing to and render that. I'm actually a little worried these comments won't be storing what comment they're on and we won't be able to provide a migration to fix comments caught in this window where core__comment_links aren't being produced.

[ayleph]

Thanks, that helps clarify the way the code should behave. Inline responses below.

Replying to Tsyesika:

The fix is to ensure the Comment (core__comment_links) entry is being made

Yes, I can see an entry is being made in core__comment_links, based on the timestamp.

Replying to Tsyesika:

and use that id in the URLs

This part is not happening. The URLs on the media page and in the comment notification emails are being generated with the comment_id from core__media_comments.

Replying to Tsyesika:

this then should look up the comments and dereference the comment it's pointing to and render that.

This part isn't happening either. If I match timestamps between core__media_comments and core__comment_links and manually enter a URL using the id from core__comment_links, it does not render the correct comment object.

Replying to Tsyesika:

I'm actually a little worried these comments won't be storing what comment they're on and we won't be able to provide a migration to fix comments caught in this window where core__comment_links aren't being produced.

Bingo. I think something's not right here. I think it's odd that my core__comment_links table contains 23 entries, while my core__media_comments table contains 32 entries. So far I've seen this on both of my instances that have been migrated from previous code. I wonder if I'd still see this on a brand new instance created with the migrations already in place.

[Jessica Tallon]

I'll put this on the front of my queue tomorrow for things I should work on, I'll do my best to have a fix ASAP. Hopefully there will be a way to fix this for instances like yours where there is clearly a disconnect between the Comment and TextComment model though I'm not sure how that would work right now.

[ayleph]

Thanks Tsyesika! I'm not too concerned about the disconnect between Comment and TextComment on my instances. If we can get the rest of it working correctly, I can probably manually update fields in the database by comparing timestamps. Or I can just ignore the issue for older comments and let newer comments get set correctly.

[Jessica Tallon]

Replying to ayleph:

I was just able to reproduce this issue with current master (​062e378) on an instance running sqlite.

Steps to reproduce:

• Create two users (user A and user B).
• Log in as user A. Upload a picture. Log out of user A.
• Log in as user B. Comment on picture from user A. Log out of user B.
• Log in as user A. Click on new comment notification icon next to dropdown arrow. Click on timesince link (says something like "0 minutes ago") next to user B's name.

I have tried to reproduce this using these steps, including using SQLite however I have been unable to. I clicked the timestamp link as you instructed and it just took me to the media entry page with the comment highlighted as intended. I did however decide I'd dig a bit further and look at the code, check the Comment (core__comment_links) table is being populated, indeed it is and also to check the URLs being used.

I noticed the URLs and functions all still worked around simply handling the CommentText, that didn't matter so much since that's the only kind of comments the mediagoblin code is going to accept however at some point they will move to accept lots of different types. I have pushed as of ​6efcab2 this changes Notification.object_id to use the Comment not TextComment ID, I also have a migration to convert. Please can you pull and check again and ensure you're following these steps on a fresh instance and report back.

[ayleph]

I pulled and ran all migrations, but I'm not sure 6efcab2 is working as intended. I'm still seeing comment links being generated based on the ID from TextComment (core__media_comments), not the ID from Comment (core__comment_links).

Here's an example of a comment I just made.

sqlite> select * from core__media_comments order by updated desc limit 1;
25|5|2016-03-01 06:07:36.363180|test comment|||2016-03-01 06:07:36.363192
sqlite> 
sqlite> select * from core__comment_links order by added desc limit 1;
22|90|91|2016-03-01 06:07:36.408867

Here's the relevant html showing it's using Comment Id 25 from core__media_comments instead of Comment ID 22 from core__comment_links.

       <li id="comment-25"
            class="comment_wrapper">
          <div class="comment_author">
            <img src="/mgoblin_static/images/icon_comment.png" />
            <a href="/u/machalus/"
               class="comment_authorlink">machalus</a>
            <a href="/u/machalus/m/unknown-jpe/c/25/#comment"
               class="comment_whenlink">
              <span title='06:07AM 2016-03-01'>0 minutes ago</span></a>:
          </div>
          <div class="comment_content">
            <p>test comment</p>
          </div>

[ayleph]

I see now that the email notification URL and the notification header URL now give a link with the Commented ID from core__comment_links. It still needs to be updated on the media page though.

[Jessica Tallon]

I'll make sure that happens, does the new link work for you or does it cause the same error?

[Jessica Tallon]

Okay, I've pushed another fix, it should fix the link in the media view as you mentioned above, I've also fixed some other issues I found. If you pull you should be able to test the changes. Let me know if this is still an issue.

Hopefully fixed as of ​161bc6b.

[ayleph]

Replying to Tsyesika:

does the new link work for you or does it cause the same error?

As of the changes in 6efcab2, the new link provided in email notification and notification header took me to the media page without causing a server error, but the comment on the page was not highlighted. I'll test again with the new changes and report back.

[ayleph]

Good news all around! After applying the changes in 161bc6b, the link provided in email notification works, and the comment is highlighted on the page as expected. Ditto for the link in the notification header. Also, the link on the media page is now correct.

This ticket is almost wrapped up, but I think there are a couple more places where this change needs to be made. It looks like the following pages may need some attention.

mediagoblin/templates/mediagoblin/user_pages/report.html
mediagoblin/templates/mediagoblin/user_pages/blog_media.html
mediagoblin/templates/mediagoblin/moderation/report.html

I'll try to investigate these and see whether they need updates or not. Unfortunately, #5432 may prevent me from fully testing.

[ayleph]

I applied fix ​690597e for #5432, which I just noticed reverts a change that was made in ​161bc6b. 161bc6b changed the Report link to use comment_object.id as the ID, but this didn't work. It needed to be comment.id, same as is used in in request.urlgen on line 143. This makes sense, right? We're creating URLs based on the Comment ID, not the TextComment (comment.comment_object) ID.

[ayleph]

I've got a fix for mediagoblin/templates/user_pages/report.html which fixes the comment ID and updates some code to exactly match the code in mediagoblin/templates/user_pages/media.html.

[ayleph]

It's going to be tricker to fix mediagoblin/templates/mediagoblin/moderation/report.html. The report view passes the TextComment object as the report object. I don't know how to back out the Comment ID from the TextComment object.

[ayleph]

The fix for mediagoblin/templates/user_pages/report.html is applied as of ​b1d4973. The following two pages still need to be addressed.

mediagoblin/templates/mediagoblin/user_pages/blog_media.html
mediagoblin/templates/mediagoblin/moderation/report.html

At this point, comment links no longer cause server errors. The outstanding issues involve correcting links which point to the wrong locations. This is an annoyance, but it's not a blocker. I'm going to change the severity of the ticket to match.

[ayleph]

Fix for mediagoblin/templates/user_pages/blog_media.html is applied as of ​512ed08. To actually make use of this, you'll probably need to apply the patches in #5437.

The only remaining affected page is one that's tricky for me as mentioned in comment 35.

mediagoblin/templates/mediagoblin/moderation/report.html

[ayleph]

The remaining code to be changed before closing this ticket is of such little importance that I'm going to remove the 0.9.0 tag from this ticket. The impact of not addressing this is that when someone views a reported comment, the link on that comment may not go to the correct page. This use case alone is limited to admins and moderators. I think there's basically no harm in removing this from the 0.9.0 release target.

[Boris Bobrov]

I would appreciate review of this patch. Does it fix the issue? Does it break anything?

[ayleph]

Thanks for the patch! I applied to my development instance. Here are the results.

For comments which have been reported before the patch was applied, clicking on the report link now goes to a page which says "CONTENT BY <user> HAS BEEN DELETED." The comment has not been deleted, but this is the response when report.is_comment_report() returns false, as the patch has changed the model to expect a Comment object instead of a TextComment object.

For comments which have been reported after the patch was applied, clicking on the report link shows the report as expected. From there, clicking on the "x minutes ago" text shows the comment properly highlighted. This is the desired behavior.

As expected, the database shows that the pre-patch comment object is a TextComment, and the post-patch comment object is a Comment. I didn't go so far as to try changing the object type, because I figured that would cause another error down the line. In my case, I can just mark the old TextComment reports as resolved and ignore them.

I think this patch is probably okay. It seems to solve the issue going forward, and I don't know if there's any good way to fix the old reports. I'm not quite sure if this fits Tsyesika's initial plan, but it seems to work.

[Boris Bobrov]

Right, this need a migration. Will do today.