Skip to:
Content

BuddyPress.org

Opened 12 years ago

Closed 10 years ago

Last modified 10 years ago

#4310 closed enhancement (fixed)

Members Profile Shows "active sometime ago"

Reported by: frank13's profile frank13 Owned by: djpaul's profile DJPaul
Milestone: 2.1 Priority: normal
Severity: normal Version: 1.5.6
Component: Core Keywords: has-patch commit
Cc:

Description

It seems that whenever someone has logged into our BuddyPress instance within the last 10-15 minutes or less they always show up as "active sometime ago".

I looked at the BP code and I see that there is a catch all if() statement that throws "sometime" whenever the script can't properly calculate the elapsed time. It always happens when the elapsed time is 10-15 minutes or less.

I believe this is a bug. It is also a misleading message to your community members as people ask me "what does sometime ago" represent.

Thanks for fixing.

Attachments (3)

4310.01.patch (1.3 KB) - added by r-a-y 10 years ago.
4310.unittest.patch (848 bytes) - added by r-a-y 10 years ago.
Amended to backup current timezone and restore it after unit test
4310.02.patch (2.8 KB) - added by boonebgorges 10 years ago.

Download all attachments as: .zip

Change History (42)

#1 @boonebgorges
12 years ago

  • Keywords reporter-feedback added

I can't reproduce this. Mine is accurate to the minute. And it's hard to guess what might be causing this issue.

The only thing I can think of is that your PHP time is not the same as your system time. Are timestamps accurate through your BP and WP installations? Is there any chance that you can do some deeper debugging to see where the conversion is going amiss?

#2 @frank13
12 years ago

Thanks @boonebgorges.

I just ran a unix date command from the shell command line:
Tue Jul 10 09:39:08 EDT 2012

I ran a PHP date() script in the browser as close to same time I executed unix command as possible:
July 10, 2012 at 9:39:09 AM

Being off by only 1 second, I have to believe the system clock and PHP clock are in sync.

When you say dig deeper, I did look at the BP code and noticed that if the elapsed time calculation is illogical (meaning a negative) then BP displays "active sometime ago". I am tracking a user session now to see when the calculation actually begins to track properly. I believe it starts tracking properly once a member is inactive for 1 hour or more, but I'll have to wait awhile to confirm that assumption.

#3 @frank13
12 years ago

Further,

In my WP General Settings:
Local time is 2012-07-10 9:50:23

At same time, unix date command is:
Tue Jul 10 09:50:21 EDT 2012

So those 2 are the same as well.

#4 follow-up: @boonebgorges
12 years ago

if the elapsed time calculation is illogical (meaning a negative) then BP displays "active sometime ago"

Yes, that's correct. So the question is where we're getting a mismatch between activity time and system time. You may want to put some debug statements into bp_core_time_since() (bp-core/bp-core-functions.php), to get a sense of which times are being reported incorrectly.

#5 in reply to: ↑ 4 @frank13
12 years ago

Replying to boonebgorges:

if the elapsed time calculation is illogical (meaning a negative) then BP displays "active sometime ago"

Yes, that's correct. So the question is where we're getting a mismatch between activity time and system time. You may want to put some debug statements into bp_core_time_since() (bp-core/bp-core-functions.php), to get a sense of which times are being reported incorrectly.

Yeah, I am already onto that...putting in some try-catch displays...I'll report back.

#6 @frank13
12 years ago

Found it @boonepgorges

bp_core_current_time() is 2012-07-10 14:15:34

Clock time is actually 10:15am and not 2:15pm.

How do I get bp_core_current_time() to know that the clock time is 4 hours earlier than it thinks it is?

#7 follow-up: @boonebgorges
12 years ago

How do I get bp_core_current_time() to know that the clock time is 4 hours earlier than it thinks it is?

That's easy - there is a filter 'bp_core_current_time' that you can use to change its output to whatever you want.

A more important question is why bp_core_current_time() is returning the wrong time to begin with. What time zone are you in? Is current_time() (wp-includes/functions.php) working correctly for you? If gmdate() is returning an incorrect time, then you might have a PHP configuration issue.

#8 in reply to: ↑ 7 ; follow-up: @frank13
12 years ago

Replying to boonebgorges:

How do I get bp_core_current_time() to know that the clock time is 4 hours earlier than it thinks it is?

That's easy - there is a filter 'bp_core_current_time' that you can use to change its output to whatever you want.

A more important question is why bp_core_current_time() is returning the wrong time to begin with. What time zone are you in? Is current_time() (wp-includes/functions.php) working correctly for you? If gmdate() is returning an incorrect time, then you might have a PHP configuration issue.

We are in Time Zone "EST", "New York", "GMT-5"
WordPress Settings:
Timezone New York UTC time is 2012-07-10 14:43:28 Local time is 2012-07-10 10:43:28
Choose a city in the same timezone as you.
This timezone is currently in daylight saving time.

PHP Settings:
date/time support enabled
"Olson" Timezone Database Version 2009.13
Timezone Database internal
Default timezone US/Eastern

current_time() returns nothing [from within the bp-core-functions.php script]

gmdate('m/d/y g:i:s a') = 07/10/12 2:51:38 pm [that's not right]

Finally, it can't be a PHP settings issue because the server I have WP/BP installed on has been running for years and we have thousands of PHP apps running on it. never had a date-time issue with any of them.

#9 follow-up: @boonebgorges
12 years ago

gmdate('m/d/y g:i:s a') = 07/10/12 2:51:38 pm [that's not right]

That *is* right. gmdate() is supposed to return the current UTC time. So...

Found it @boonepgorges
bp_core_current_time() is 2012-07-10 14:15:34

That actually isn't the problem. bp_core_current_time(), with default parameters, is designed to return UTC, so it appears to be working correctly.

So the problem must be with the other date ($older_date) being used to calculate bp_core_time_since(). In the case of "last active" dates, this ultimately comes from a key in the wp_usermeta table called 'last_activity'. As you can see in bp_core_record_activity() (also in bp-core-functions.php), that data should be stored as UTC as well, but it's possible that it's not. Can you check the database to see? For some recently active user with numeric ID N (assuming you're using the default db prefix 'wp_'),

SELECT * FROM wp_usermeta WHERE user_id = N AND meta_key = 'last_activity';

#10 in reply to: ↑ 9 @frank13
12 years ago

Replying to boonebgorges:

gmdate('m/d/y g:i:s a') = 07/10/12 2:51:38 pm [that's not right]

That *is* right. gmdate() is supposed to return the current UTC time. So...

Found it @boonepgorges
bp_core_current_time() is 2012-07-10 14:15:34

That actually isn't the problem. bp_core_current_time(), with default parameters, is designed to return UTC, so it appears to be working correctly.

So the problem must be with the other date ($older_date) being used to calculate bp_core_time_since(). In the case of "last active" dates, this ultimately comes from a key in the wp_usermeta table called 'last_activity'. As you can see in bp_core_record_activity() (also in bp-core-functions.php), that data should be stored as UTC as well, but it's possible that it's not. Can you check the database to see? For some recently active user with numeric ID N (assuming you're using the default db prefix 'wp_'),

SELECT * FROM wp_usermeta WHERE user_id = N AND meta_key = 'last_activity';

Here is a dump of the members that have logged in today:
Full Texts umeta_id user_id meta_key meta_value Descending

Edit Delete 152 7 last_activity 2012-07-10 15:07:43
Edit Delete 36 1 last_activity 2012-07-10 15:07:20
Edit Delete 434 8 last_activity 2012-07-10 14:34:26
Edit Delete 63 3 last_activity 2012-07-10 14:21:00
Edit Delete 437 15 last_activity 2012-07-10 13:32:31
Edit Delete 602 23 last_activity 2012-07-10 13:32:23
Edit Delete 231 12 last_activity 2012-07-10 12:24:04

Their times appear to be stored in UTC

Last edited 12 years ago by frank13 (previous) (diff)

#11 follow-up: @boonebgorges
12 years ago

Their times appear to be stored in UTC

Yes. So it appears that the problem is in between the database and bp_core_time_since(). You'll need to place some more debug statements along the trace to see what's going on.

What are the values being passed into bp_core_time_since()? Are they correct?

#12 in reply to: ↑ 11 @frank13
12 years ago

Replying to boonebgorges:

Their times appear to be stored in UTC

Yes. So it appears that the problem is in between the database and bp_core_time_since(). You'll need to place some more debug statements along the trace to see what's going on.

What are the values being passed into bp_core_time_since()? Are they correct?

Ok, I'll venture on. But it is peculiar to me why I am having this issue and conceivably no one else is...

#13 follow-ups: @boonebgorges
12 years ago

But it is peculiar to me why I am having this issue and conceivably no one else is...

It's peculiar to me too. That's why I'm taking the time to attempt to debug it with you :)

#14 in reply to: ↑ 13 @frank13
12 years ago

Replying to boonebgorges:

But it is peculiar to me why I am having this issue and conceivably no one else is...

It's peculiar to me too. That's why I'm taking the time to attempt to debug it with you :)

Thanks, appreciate it.

To give you a status then, I have to attend back-to-back meetings now. I won't be back to my office until 3pm to continue working on this. It is noon here on East Coast US. So I will be posting back in about 3-3½ hours.

#15 in reply to: ↑ 13 @frank13
12 years ago

Replying to boonebgorges:

But it is peculiar to me why I am having this issue and conceivably no one else is...

It's peculiar to me too. That's why I'm taking the time to attempt to debug it with you :)

Ok @boonepgorges -- I am in between meetings until 2pm (20 minutes from now).

Here is what I dumped:
PHP date('g:i:s a') from within WP/BP = 7:32:52 pm
bp_core_time_since( $older_date ) = 2012-07-10 17:30:28 [on first member in list filtered by Last Active]
bp_core_time_since( $newer_date ) = 'null'
$since [from within bp_core_time_since()] = -7056

But what is interesting is that PHP date('g:i:s A') from a script I ran through a browser outside the WP/BP installation, yet on the same server, returns = 1:32:49 PM (which is the actual clock time)

How can that be?

Last edited 12 years ago by frank13 (previous) (diff)

#16 in reply to: ↑ 8 @frank13
12 years ago

Replying to frank13:

Replying to boonebgorges:

That's easy - there is a filter 'bp_core_current_time' that you can use to change its output to whatever you want.

@boonepgorges - could you be kind enough to show me what the filter command for bp_core_current_time would look like so I could add it to my functions.php file in my theme and manually control the datetime stamp?

Thanks.

Version 0, edited 12 years ago by frank13 (next)

#17 follow-up: @boonebgorges
12 years ago

boonepgorges

'b' not 'p'

How can that be?

During its loading process, WP sets your runtime timezone to UTC https://core.trac.wordpress.org/browser/tags/3.4.1/wp-settings.php#L35. So that's why date() is returning something different inside and outside of WP. I still don't understand how it is causing the problem originally reported in this ticket, though, because regardless of whether WP's internal time matches your system time, the fact is that BP is using WP's time for last_activity as well as for *now*, which means that time comparisons ("x minutes ago") should work just fine.

could you be kind enough to show me what the filter command for bp_core_current_time would look like

Here's the syntax:

function bbg_do_something_to_current_time( $time ) {
   // do stuff to $time (or provide a whole new value), and then return it
   
   return $time;
}
add_filter( 'bp_core_current_time', 'bbg_do_something_to_current_time' );

#18 in reply to: ↑ 17 @frank13
12 years ago

oops, sorry @boonebgorges. Completely accidental on my part.

Ok, so I tried 2 attempts to manually alter the datetime for member activity processing.

(Attempt 1) this was added to my functions.php script document in my theme directory in order to set the internal time clock to a time slightly earlier than the actual clock:
`function bbg_do_something_to_current_time( $time ) {

do stuff to $time (or provide a whole new value), and then return it

$time = '2012-07-11 09:15:00';

return $time;

}
add_filter( 'bp_core_current_time', 'bbg_do_something_to_current_time' );`

(Attempt 2) this was added to my functions.php script document in my theme directory in order to set the internal time clock to a time slightly later than the actual clock:
`function bbg_do_something_to_current_time( $time ) {

do stuff to $time (or provide a whole new value), and then return it

$time = '2012-07-11 09:30:00';

return $time;

}
add_filter( 'bp_core_current_time', 'bbg_do_something_to_current_time' );`

Both attempts failed to show my users active since a real time rather than "active sometime ago"

#19 @boonebgorges
12 years ago

Both attempts failed to show my users active since a real time rather than "active sometime ago"

That may be. But this assumes that bp_core_current_time() is root of your original problem, which I've hypothesized it's not (because the times are relative). In any case, the only real way to see whether the filters are doing what they're intended to do is to dump the value of bp_core_current_time() to your screen; if it's showing the times you've entered in your filters, then the filters are working.

I remain convinced that we haven't really narrowed in on the real culprit, and more debugging is needed to find the point where the divergence in timestamps is taking place. Given that we know that the last_activity values in the DB are correct (I'm not sure that we do know this, as you posted these https://buddypress.trac.wordpress.org/ticket/4310#comment:10 without comment - but I'm assuming they're correct), it's a pretty short chain from there to the "since" text. The trace looks something like this (in the member directory - it's slightly different elsewhere):

1) BP_Core_User::get_users() (the query joins against the usermeta table to get the last_activity value)
2) bp_get_member_last_active() (the template function that pulls the information out of the query object)
3) bp_core_get_last_activity() (called by bp_get_member_last_active() to format the last active string)
4) bp_core_time_since() (called by bp_core_get_last_activity() to convert the last active date into a 'since' string)

(I've left out a couple of finer points, but these are the ones where, IMO, there is the possibility of breakage.)

At each of these points, drop debug statements to make sure that the timestamps are matching up properly. In the case of bp_core_time_since(), you may have to do a line-by-line debug, to see if the problem is being introduced with the auto-detection of $newer_time. In any case, the issue arises somewhere along this stack.

#20 @frank13
12 years ago

Below is the correct code to make the bp_core_time_since() work properly. I updated bp-core-functions.php and now my times get computed properly.

	//$newer_date = ( !$newer_date ) ? strtotime( bp_core_current_time() ) : $newer_date;
	if ( !$newer_date ) {
		$time_chunks = explode( ':', str_replace( ' ', ':', bp_core_current_time() ) );
		$date_chunks = explode( '-', str_replace( ' ', '-', bp_core_current_time() ) );
		$newer_date  = gmmktime( (int)$time_chunks[1], (int)$time_chunks[2], (int)$time_chunks[3], (int)$date_chunks[1], (int)$date_chunks[2], (int)$date_chunks[0] );
	}

backticks are not working here so the first line $newer_date is actually commented out in my script file.

Last edited 12 years ago by boonebgorges (previous) (diff)

#21 follow-up: @boonebgorges
12 years ago

Below is the correct code to make the bp_core_time_since() work properly

The operative change here is that you're converting $newer_date into UTC. But you should not need to do this: bp_core_current_time() is *already* UTC. You are double converting. For instance, for UTC 1230 (8:30am Eastern time), you are running it through gmmktime as if it were a local time. Thus, if I'm understanding correctly, it's *adding* 4 hours, to give you the equivalent of UTC 1630.

The fact that this works for you means that one of the following two things are happening:

1) last_activity items are being recorded with a date that is off by 8 hours; or
2) bp_core_current_time() is giving you a local time rather than UTC

It seems like, in the discussion above, we've ruled out both possibilities. But they seem like the only possibilities, given the new code you've posted.

It sounds as if we may not get to the bottom of this. I highly, highly suggest that you move your core modifications to a filter, either on bp_core_current_time, or on the template functions bp_get_last_activity and bp_member_last_active. If you leave the current fix in place, it will be overwritten every time you update BuddyPress.

#22 in reply to: ↑ 21 @frank13
12 years ago

Replying to boonebgorges:

Below is the correct code to make the bp_core_time_since() work properly

The operative change here is that you're converting $newer_date into UTC. But you should not need to do this: bp_core_current_time() is *already* UTC. You are double converting. For instance, for UTC 1230 (8:30am Eastern time), you are running it through gmmktime as if it were a local time. Thus, if I'm understanding correctly, it's *adding* 4 hours, to give you the equivalent of UTC 1630.

The fact that this works for you means that one of the following two things are happening:

1) last_activity items are being recorded with a date that is off by 8 hours; or
2) bp_core_current_time() is giving you a local time rather than UTC

It seems like, in the discussion above, we've ruled out both possibilities. But they seem like the only possibilities, given the new code you've posted.

It sounds as if we may not get to the bottom of this. I highly, highly suggest that you move your core modifications to a filter, either on bp_core_current_time, or on the template functions bp_get_last_activity and bp_member_last_active. If you leave the current fix in place, it will be overwritten every time you update BuddyPress.

Thanks @boonebgorges. I have a lengthy and detailed document that itemizes all the core changes I have made. I have needed to re-apply them twice now as I have upgraded WP and the BP Plug-in. I am a newbie to adding filters and learning along the way. I want to put all my hacks into custom overrides so I don't have to mod core files each time I do an upgrade, but I am not clear on where, how, when to do filters. Limping along as we go...thanks again.

#23 @frank13
12 years ago

  • Type changed from defect (bug) to enhancement

#24 @r-a-y
12 years ago

This could be a related problem with #4324.

In that ticket, I tell the user to var_dump current_time() which is what bp_core_current_time() is using.

We might have to look into the current_time() function to see where the culprit is.

#25 @boonebgorges
12 years ago

  • Milestone changed from Awaiting Review to Future Release

Moving to Future Release so that we can examine in better depth at some future point.

#26 @tobyhawkins
10 years ago

Sorry if I'm being dumb here, but isn't the problem the use of strtotime() on line 803 in bp-core-functions?

As I understand it, strtotime() uses the default local timezone when calculating the Unix timestamp. bp_core_current_time() should always be in UTC, which means when you put it into strtotime() the function will assume it's looking at a local time and try and convert it to UTC, resulting in a discrepancy in the timestamps if the server time is anything other than UTC.

In the previous lines, gmmktime() is used to convert the $older_date, which should be a UTC time stored in the database. It would make sense to convert bp_core_current_time() (which should be UTC) into a timestamp using gmmktime() as well.

#27 @r-a-y
10 years ago

  • Keywords has-patch needs-testing added; needs-patch reporter-feedback removed

As I understand it, strtotime() uses the default local timezone when calculating the Unix timestamp.

Thanks for the feedback. It's something I've suspected in the past (comment:24).

In 01.patch, I've added a new parameter to bp_core_current_time() so we can use the UNIX timestamp instead of the MySQL date and changed bp_core_time_since() to use this parameter and removed the strtotime() usage.

Untested, but let me know if this works for you, tonyhawkins or frank13. I want to try this before moving towards the gmmktime() approach.

Last edited 10 years ago by r-a-y (previous) (diff)

@r-a-y
10 years ago

#28 @tobyhawkins
10 years ago

I was fixing it by adding ' . "GMT"' to bp_core_current_time() on the line in question - not very elegant, I realise.

However, I've changed to your patch and that works great except you need to switch 'timestamp' and 'mysql' in the if...else... statement within bp_core_current_time()

Last edited 10 years ago by tobyhawkins (previous) (diff)

#29 @tobyhawkins
10 years ago

... or by changing false to true. You got there before I replied it seems :)

Last edited 10 years ago by tobyhawkins (previous) (diff)

#30 @r-a-y
10 years ago

... or by changing false to true. You got there before I replied it seems :)

Yeah, I wasn't 100% awake yet!

So, to confirm, you were running into this issue, but the patch fixes the problem? If so, I'm going to commit it in a bit pending feedback from another core dev.

#31 @tobyhawkins
10 years ago

Superficially, yes, this patch seems to do the trick. I'm not fully acquainted with every facet of BuddyPress yet, so I couldn't say that this doesn't break something else, but it definitely fixes the issue I was having.

Thanks for your input :)

#32 @boonebgorges
10 years ago

  • Keywords needs-unit-tests added

The logic looks right, but for a change with this level of visibility, I'd really like to see a unit test that fails with the current config but passes with the change.

#33 @r-a-y
10 years ago

  • Keywords needs-testing needs-unit-tests removed

I'd really like to see a unit test that fails with the current config but passes with the change.

I had a feeling you were going to say that ;)

I've attached a unit test. 01.patch passes the test :)

@r-a-y
10 years ago

Amended to backup current timezone and restore it after unit test

#34 @boonebgorges
10 years ago

  • Keywords commit added
  • Milestone changed from Future Release to 2.1

Thanks, r-a-y :) I wrote a second test (I don't trust 'right now' for some reason) and combined the patches into a single ticket. Let's go with this, but be vigilant about watching for repercussions in the lead-up to 2.1.

#35 @tobyhawkins
10 years ago

I'll put the patch on our live site at some point this week and keep an eye on it too..

#36 @DJPaul
10 years ago

  • Owner set to DJPaul
  • Status changed from new to assigned

Let's get this in.

#37 @tobyhawkins
10 years ago

I've had the patch live since 7th July and haven't had any problems.

#38 @r-a-y
10 years ago

  • Resolution set to fixed
  • Status changed from assigned to closed

In 8676:

Fix issues with bp_core_time_since().

Previously, when the $newer_date parameter isn't passed, we generated a
UNIX timestamp using strtotime() and bp_core_current_time(). strtotime()
uses the default timezone, which can cause timezone discrepencies if the
server time is not UTC.

This commit removes the strtotime() usage and refactors bp_core_current_time()
to accept current_time()'s 'type' parameter. This allows us to correctly
grab the UTC timestamp when setting bp_core_current_time()'s second
argument to 'timestamp'.

Commit also adds some unit tests.

Fixes #4310.

#39 @r-a-y
10 years ago

In 8788:

Tests: Change 'right now' condition test for bp_core_time_since() to '1 minute ago'

boonebgorges was right. The 'right now' condition is too finicky to test
for. Caused this unit test to fail in some instances.

See #4310.

Note: See TracTickets for help on using tickets.