XF 2.0 "Replier can only add posts at the end of a thread" error

R

rfc0001

Well-known member
I've gotten this server error 6 times today on the same thread. Any ideas?

Error
  • LogicException: Replier can only add posts at the end of a thread
  • src/XF/Service/Thread/Replier.php:176
Stack trace
#0 src/XF/Service/Thread/Replier.php(159): XF\Service\Thread\Replier->setPostPosition(Array)
#1 src/XF/Service/ValidateAndSavableTrait.php(40): XF\Service\Thread\Replier->_save()
#2 src/XF/Pub/Controller/Thread.php(431): XF\Service\Thread\Replier->save()
#3 src/XF/Mvc/Dispatcher.php(249): XF\Pub\Controller\Thread->actionAddReply(Object(XF\Mvc\ParameterBag))
#4 src/XF/Mvc/Dispatcher.php(88): XF\Mvc\Dispatcher->dispatchClass('XF:Thread', 'AddReply', 'json', Object(XF\Mvc\ParameterBag), 'forums', Object(Andy\WhoVoted\XF\Pub\Controller\Thread), NULL)
#5 src/XF/Mvc/Dispatcher.php(41): XF\Mvc\Dispatcher->dispatchLoop(Object(XF\Mvc\RouteMatch))
#6 src/XF/App.php(1891): XF\Mvc\Dispatcher->run()
#7 src/XF.php(328): XF\App->run()
#8 index.php(13): XF::runApp('XF\\Pub\\App')
#9 {main}

Request state
array(4) {
["url"] => string(60) "/forum/threads/woody%E2%80%99s-lunch-box-menu.7763/add-reply"
["_GET"] => array(0) {
}
["_POST"] => array(9) {
["message_html"] => string(39) "<p>BBQ brisket melt for me, please!</p>"
["attachment_hash"] => string(32) "389f6935204f409952bc67b21880865d"
["attachment_hash_combined"] => string(86) "{"type":"post","context":{"thread_id":7763},"hash":"389f6935204f409952bc67b21880865d"}"
["last_date"] => string(10) "1523736840"
["last_known_date"] => string(10) "1523736840"
["_xfToken"] => string(8) "********"
["_xfRequestUri"] => string(51) "/forum/threads/woody%E2%80%99s-lunch-box-menu.7763/"
["_xfWithData"] => string(1) "1"
["_xfResponseType"] => string(4) "json"
}
}

Running XF 2.0.4
 
Sort by date Sort by votes
rfc0001 said:
Nevermind, looks like the post date was in the future.
Click to expand...

Let's revisit. I get this error message at least 1 time per day.

What I know.
I'm the admin, and know the clocks on our web server are dead-on.

Code: 
mtbnj.com@n11:~/tools$ cat check_time.sh
#!/bin/bash

echo
echo Apache Server Time
TZ=PST8PDT date +"%Y-%m-%d %H:%M:%S"

echo
echo MySQL Server Time
echo "select now();" | mysql --silent -uUSER -pPASSWORD -h ${DATABASE_SERVER}
echo
mtbnj.com@n11:~/tools$ ./check_time.sh

Apache Server Time
2020-03-04 05:58:30

MySQL Server Time
2020-03-04 05:58:30

mtbnj.com@n11:~/tools$

It has happened when I posted, so I could quickly check the previous message, and it says something like 'posted in a moment.'
Before updating to XF 2.1.7 and php 7.3.11, I would occasionally get messages posted 5 minutes into the future.
This has resolved.

Here is the stack trace from my last error - but we know it isn't this post that is creating the error, it is the previous one.

Code: 
Server error log
LogicException: Replier can only add posts at the end of a thread src/XF/Service/Thread/Replier.php:196
Generated by: The Governor of Slacktown Mar 3, 2020 at 5:41 PM
Stack trace
#0 src/XF/Service/Thread/Replier.php(179): XF\Service\Thread\Replier->setPostPosition(Array)
#1 src/XF/Service/ValidateAndSavableTrait.php(40): XF\Service\Thread\Replier->_save()
#2 src/XF/Pub/Controller/Thread.php(461): XF\Service\Thread\Replier->save()
#3 src/XF/Mvc/Dispatcher.php(350): XF\Pub\Controller\Thread->actionAddReply(Object(XF\Mvc\ParameterBag))
#4 src/XF/Mvc/Dispatcher.php(257): XF\Mvc\Dispatcher->dispatchClass('XF:Thread', 'AddReply', Object(XF\Mvc\RouteMatch), Object(XF\Pub\Controller\Thread), NULL)
#5 src/XF/Mvc/Dispatcher.php(113): XF\Mvc\Dispatcher->dispatchFromMatch(Object(XF\Mvc\RouteMatch), Object(XF\Pub\Controller\Thread), NULL)
#6 src/XF/Mvc/Dispatcher.php(55): XF\Mvc\Dispatcher->dispatchLoop(Object(XF\Mvc\RouteMatch))
#7 src/XF/App.php(2184): XF\Mvc\Dispatcher->run()
#8 src/XF.php(391): XF\App->run()
#9 index.php(20): XF::runApp('XF\\Pub\\App')
#10 {main}
Request state
array(4) {
  ["url"] => string(51) "/forum/threads/how-to-ride-in-crocs.47650/add-reply"
  ["referrer"] => string(70) "https://www.mtbnj.com/forum/threads/how-to-ride-in-crocs.47650/page-57"
  ["_GET"] => array(0) {
  }
  ["_POST"] => array(9) {
    ["message_html"] => string(126) "<p>[QUOTE="Paul H, post: 964250, member: 10281"]</p><p>Why?</p><p>[/QUOTE]</p><p><br></p><p>60 bucks for nukeproof ones...</p>"
    ["attachment_hash"] => string(32) "8df6cc614074586fa4fcf12b62c747ec"
    ["attachment_hash_combined"] => string(87) "{"type":"post","context":{"thread_id":47650},"hash":"8df6cc614074586fa4fcf12b62c747ec"}"
    ["last_date"] => string(10) "1583275297"
    ["last_known_date"] => string(10) "1583275297"
    ["_xfToken"] => string(8) "********"
    ["_xfRequestUri"] => string(49) "/forum/threads/how-to-ride-in-crocs.47650/page-57"
    ["_xfWithData"] => string(1) "1"
    ["_xfResponseType"] => string(4) "json"
  }
}

It is not a browser issue. On my windows box, I set the time 5 minutes fast, and posted from Chrome and Edge.
Local time does not effect db post time.

So simple enough, i go into XF_post and find the offending record. It looks like (sql code generated by my DB browser)

SQL: 
INSERT INTO `xf_post` (`post_id`, `thread_id`, `user_id`, `username`, `post_date`, `message`, `ip_id`, `message_state`, `attach_count`, `position`, `reaction_score`, `reactions`, `reaction_users`, `warning_id`, `warning_message`, `last_edit_date`, `last_edit_user_id`, `edit_count`, `embed_metadata`) 
VALUES ('964250', '47650', '10281', 'Paul H', '1583275297', '[QUOTE="The Governor of Slacktown, post: 964249, member: 9000"]
I''m contemplating carbon bars, someone talk me out of it...
[/QUOTE]
Why?', '1897689', 'visible', '0', '1124', '0', '[]', '[]', '0', '', '0', '0', '0', '[]')

I find the same 'post_date' as my error trace - which i'll postulate that XF is doing its own thing, rather than using a TIMESTAMP (or DATETIME)

- I would expect that I could hit 'reply' a second later, and it would go,
but it doesn't. I have to wait until the previous post "vests" -
This would lead me to believe the post_date on my record is also in the future.....since they are the same.

If XF is doing its own thing with the post_date field, it isn't catching something with its call to "time()"
or it is a classic time manipulation error (ie using (int)x/100 to get seconds vs /60) or
some other issues with conversion from their epoch (or the local epoch - if they do it that way)
I've also seen some string conversion errors where 0/1 are mis-typed as O/l, and extremely hard to locate.

Anyway, i'd like to see the source of this error identified - it is going to be a tough one, as there are only a few
reports on here, since it has been claimed 'not a bug' - Well it isn't a feature, unless it is being put into the DB
in the future to throttle posts (which doesn't make sense, because it then manifests itself as an error.)

Anyone interested in taking this on?
Point me where to look, and i'll dig in - (i haven't started looking, so a head start would help)
 
Last edited:
Upvote 0 Downvote
This has come back - i've rebuild all the caches - and i even have
conversations "out of order" because of it.

since it seems to be install specific - (or everyone would be reporting) - i need to find a way to trace
how posts are getting into the db with a future date - ideas on where to do this?
set a trigger? why are posts allowed to happen "in the future"
 
Upvote 0 Downvote
Narrowing this down - It has something to do with a failed or delayed post, where
the time of the post_date, last_post and last_known_post in xf_post and xf_thread become inconsistent.
It also happens at a higher level which causes the new_posts page to show threads which were
already read (not bold as designed ) for longer than the designed behavior (this is described elsewhere on the site)

I've added some defensive code in an attempt to identify when this is happening.

Did receive advice to move off the shared server - as it might be a conflict with cache hits somewhere deep
inside a black hole which will be impossible to find. Still working it -
 
Upvote 0 Downvote
I've recently seen this happen on a large super-busy site under peak load before (running XF2.1.10 Patch 2).

Honestly xf_post.post_date should likely be force-set after the xf_thread record is locked via an update to ensure it is correct so this error can't happen.
 
Upvote 0 Downvote
Xon said:
I've recently seen this happen on a large super-busy site under peak load before (running XF2.1.10 Patch 2).

Honestly xf_post.post_date should likely be force-set after the xf_thread record is locked via an update to ensure it is correct so this error can't happen.
Click to expand...

Glad i'm not alone! I'm getting ready to ask my provider to switch me to a different node - perhaps there is a hw problem..
Since I'm on shared service, I have no idea of the actual load on the instance.

It looks like that your description of lock/update is happening in the code (Replier.php) - "select for update" on xf_thread record, update post count and last_post_date, last_post. then commit() it.

I'm not 100% sure of my problem description anymore -

The issue is i'm seeing is the date (time()) of a post is in the future by a couple minutes - i've seen it as much as 5.

Looking at the timestamp on the post (upper corner of the post viewing the forum) - the string time label is correct, the time() value is
incorrect and in the future. Refreshing the page changes the time string to the future -

I still don't have enough info to completely describe it (admin for this site is a for-fun endevour) -
I will write something that gets all the detail about a post when i see it.
Maybe that will help.

we are running the current version - 2.1.10_2
here is our environment.
1592337149062.webp
 
Upvote 0 Downvote
beerForo said:
This can happen if using the add-on that changes the content owner and date. If you set it to the future (even by seconds, as, you may not know what second it is when you set it) and someone replies they get the error. FYI in case using @TickTackk's aadd-on. :)
Click to expand...

TickTackk said:
Even when not using my Change Content Owner add-on you can still get this error IF the posts are being created on an extra ordinary rate such as when using my Seeder add-on.
Click to expand...

The only add-on I'm using is Ignore_Content (2.0.5) by @truonglv - which does not manipulate xf_thread or xf_post.

These posts are up to 5 minutes in the future!
Here is an example.

Screenshot 2020-06-15 at 09.39.58.webp

Screenshot 2020-06-15 at 09.39.52.webp
Screenshot 2020-06-15 at 09.42.29.webp
Screenshot 2020-06-15 at 09.41.33.webp
(i didn't scroll right for last_post_date, but it satisfies the query)

Code: 
mtbnj.com$ date --date='@1592228156'
Mon Jun 15 09:35:56 EDT 2020

This one has the time string and date-time synchronized - i've recall seeing them out-of-sync.
 
Upvote 0 Downvote

it happens at an un-extraordinary rate also. we have 500 posts/day

--------------------------------------------

here is one - i went to reply to a thread i saw. 3 minutes ago.
Screenshot 2020-06-19 at 14.57.41.webp

I posted - it threw the error, and when i refreshed

In 2 minutes

Screenshot 2020-06-19 at 14.57.56.webp

This might lead me to believe the error manifested when i tried to post, not some sort of error
on the prior post. Looking at the code, I don't see how this happens. I haven't checked the error
logic yet. might be in there.
 
Upvote 0 Downvote
Here is a weird one - I posted, the post time was correct, the label indicated in the future.
It was fine after hitting refresh.

Note the datestring on hovering, and the time in the lower right.

Screenshot 2020-06-20 at 08.41.17.webp
 
Upvote 0 Downvote
Well it ended up that my provider had a few nodes with the time off by 10 minutes.

They claim it is fixed now.

The proof i provided was a a screen shot of the time on my device, and the time returned by a simple php program with a call to time()
I then dumped the environment and found that when the time was wrong, there was a slight difference (in php.ini)
also had some scripts with wget and ssh -

more circumstantial evidence, but overwhelming. Finally got them to escalate it.
admin people figured it out right away.
 
Upvote 0 Downvote
You must log in or register to reply here.

Similar threads

F
  • Question Question
XF 2.2 LogicException: Replier can only add posts at the end of a thread in src/XF/Service/Thread/Replier.php at line 224
Replies
6
Views
626
Forum_HAKiKAT
F
S
  • Question Question
XF 2.1 Replier can only add posts at the end of a thread
Replies
1
Views
930
AndyB
AndyB
Nirjonadda
Not a bug Replier can only add posts at the end of a thread
Replies
9
Views
1K
PatMa
P
cosmin85
  • Question Question
XF 1.5 How to add social links at the end of a thread
Replies
0
Views
953
cosmin85
cosmin85
Top Bottom