XF 1.3 User "Last Activity" not getting updated

[caleb89taylor]

Hi,

Users are complaining about not getting awarded trophies (as I've mentioned before) and I've found that all the users I've checked so far have a really old last activity date. That would explain why they didn't get trophies updated. But the problem is they are posting and doing things on the boards. A user posted today asking about why he couldn't get trophy points and his last activity is marked as the same day he registered (Nov 3rd).

Where should that value be getting updated? We must have code that incorrectly updates users' last activity field.

 

[TJA]

Any unchecked entries in your Tools > Cron Entries

 

[caleb89taylor]

Any unchecked entries in your Tools > Cron Entries

Only Feeder, Record Daily Statistics, Downgrade Expired User Upgrades, and User Group Promotions.

 

[caleb89taylor]

I'm trying to think of custom code we added that could've affected that last_activity column getting updated.

We did add a check in Xenforo_Model_User::updateSessionActivity() that skips any updating if the userID is 0. We were getting slammed by queries at one point that were updating session activity with user_id = 0 so we disabled it. I'm wondering if that is blocking users who possibly use Tapatalk or something from getting that field updated.

I don't think this is the case as my own last_activity field is 10/17 and I'm on the boards almost every day and I know I've posted since then many times. Any ideas?

 

[caleb89taylor]

Update: Setting the user's last activity value to today then correctly updated their trophy points when the cron job for trophies ran. So I just need to figure out why some users aren't getting updated.

A lot of the users I saw had last_activity fields equal to the day we upgraded from 1.1 to 1.3 back in September. Pretty obvious sign we broke something somewhere.

 

[Mike]

Try running the hourly clean up cron directly via the ACP. Does it run completely?

 

[caleb89taylor]

Try running the hourly clean up cron directly via the ACP. Does it run completely?

uh I seem to be having issues. I get kicked out of the admin panel and back to the admin login page after the job has been running for a minute or two. We have had authentication issues before as we have custom auth and don't use Xenforo's.

 

[caleb89taylor]

So it appears that when I ran that hourly cleanup cron job manually that it fixed trophies for a lot of users. Even though it kicked me out to the admin login screen it must've done something as users I didn't manually fix got trophies they should've got a while ago.

@Mike You must have had a theory if you suggested running that cron job. Why did that work? Is it the

$sessionModel->updateUserLastActivityFromSessions();

line of code?

I wonder then if something is failing like the issue we had before with that cron job that stops it from running that code.

 

[Mike]

Well that particular cron script is the only that updates the last activity time. We did have a report elsewhere of last activity times not being updated and I tracked it down to an earlier step in that cron failing (relating to cleaning up millions of attachments). This failed when running manually as well.

Since it worked manually, this seems to point to the cron system you're using potentially failing. It may be worth using PHP's built in error_log setting to ensure that any error (even fatal ones or memory issues, which are hard for an app to log) gets logged to see if that sheds any more light on the issue.

 

[caleb89taylor]

Well that particular cron script is the only that updates the last activity time. We did have a report elsewhere of last activity times not being updated and I tracked it down to an earlier step in that cron failing (relating to cleaning up millions of attachments). This failed when running manually as well.

Since it worked manually, this seems to point to the cron system you're using potentially failing. It may be worth using PHP's built in error_log setting to ensure that any error (even fatal ones or memory issues, which are hard for an app to log) gets logged to see if that sheds any more light on the issue.

Yup that seems to be likely with the size of our db. I'll add some logging. Running it manually caused some errors by locking up our db because of the magnitude of the cleanup run (especially if it has been failing before and hasn't completed the expected task in a while). I'll add some logging and see if I can track down where it's failing.

 

[Mike]

The issue I ran into previously was in XenForo_Model_Attachment::deleteUnusedAttachmentData() and the workaround was to add "LIMIT 1000" to that query. (It should catch up over time.)

 

[caleb89taylor]

I'll try that just as a quick fix to see if it works but if not I'm going to add logging to narrow down where it's failing and separate out the bigger cleanup methods into separate cron jobs as that one method runs a lot of different cleanup.

 

[caleb89taylor]

Update to this. I've added logging to the cron jobs in the form of something like this:

$logDate = date("Y-m-d H:i:s", XenForo_Application::$time);
XenForo_Error::logException(new Exception("runHourlyCleanup start at $logDate"), false, 'Cron job log: ');

at the beginning and end of each cron job. After deploying the code I saw no entries in the Xenforo error log. If I run a job manually, like the hourly cleanup job, it logs the beginning and end of the cron job successfully. Does this mean cron jobs aren't even running? Or is there something that prevents XenForo_Error from logging when initiated via the async cron process?

@Mike - Sorry for the tag, but thought this thread might get buried.

 

[Mike]

That does sound like the jobs aren't running. Since you guys are triggering it via actual cron rather than the standard XF method, it sounds like something there may be involved though I don't really know what.

When I've debugged cron in the past, I've used the PHP error_log() function after ini_set'ing the error_log directive in config.php to write to a file I controlled. I could then easily add a lot of logging and allow the system to trigger as normal. Here, you could start logging from right after the XF system is initialized in script you're calling (presumably deferred.php though maybe another one).

I don't mind helping to debug but I'd need access and I don't know if that's doable. If you want to go down that route, submit a support ticket from the customer area and we'll figure out what's the best way to handle getting access.

 

[caleb89taylor]

That does sound like the jobs aren't running. Since you guys are triggering it via actual cron rather than the standard XF method, it sounds like something there may be involved though I don't really know what.

I'm not sure I understand this part. I believe we are running it via the standard XF method of cron entries set in the admin panel.

 

[caleb89taylor]

I don't mind helping to debug but I'd need access and I don't know if that's doable. If you want to go down that route, submit a support ticket from the customer area and we'll figure out what's the best way to handle getting access.

This might be an option as we've been having a lot of issues recently that may be cron related. I think we need to go back to the beginning and figure out cron problems in general.

 

[Mike]

I know you have historically run some custom code and I swore you were triggering deferred jobs via an actual cron task (every minute) rather than triggering it via the web.

Unfortunately it's difficult to talk in any real specifics as I'm not totally clear with what is and isn't working with the cron system or if there are modifications in place that are relevant.

 

[caleb89taylor]

I know you have historically run some custom code and I swore you were triggering deferred jobs via an actual cron task (every minute) rather than triggering it via the web.

Unfortunately it's difficult to talk in any real specifics as I'm not totally clear with what is and isn't working with the cron system or if there are modifications in place that are relevant.

Fair enough. I'm not sure what was in place before but as far as I know we are relying on the default XF cron job system. I'll list what I know:

1. Cron entries are enabled via admin panel > tools > cron entries and all have future run dates.
2. I can run cron jobs manually via the admin panel and they appear to work successfully (I see the output of logging I have placed in cron job functions and things like session activity gets updated and users get trophies).
3. I don't see any errors from cron jobs in the error log yet it appears like at least some of them don't run. I say this because I have added logging that should log when a cron jobs starts and ends and after watching for 6 to 7 hours I saw no logging until I ran a few cron jobs manually via the admin panel that should've been running every hour.

So basically it would be helpful to know where to look next. I think the problem lies with the how the jobs are getting triggered via the XF system. That doesn't appear to be working but unlike other forum posts related to this there aren't dates in the past for cron job "next_run" fields or anything. For all intents and purposes it seems like the system thinks the cron jobs have run even with they don't.

 

[Mike]

This is where I'd spread logging code (via error_log) throughout the whole deferred and cron system to ensure that things are actually being triggered through a regular request (rather than running it manually or calling things directly myself).

Short of access, I don't think there are any other specific recommendations I could give.