Via our Gitter channel:
@mikeruss1 wrote:
have looked at the latest Statistics reset which was yesterday. There were 8 GETS from Russia all within a second. 5 were rejected , stats reset, then the following 3 were rejected starting from ID1.
Flat files I guess?
@Maikuolan wrote:
Yeah, pretty much.
@DanielRuf made a suggestion at one of the issues recently, about a better approach to entry IDs for logging. If I implement it, I'm sure that at least a few different users will complain, that the entries IDs aren't following nice, simple, logical increments anymore. But, I think I'll implement it anyway, because implementing it would also mean that CIDRAM wouldn't need to maintain an ID counter in the cache anymore (thus rendering the problem of an ID counter resetting redundant and obsolete).
I still need to finish properly documenting how to use the supplementary cache options. Particularly, for things like the PDO option, how users can properly set up SQL databases and such things so that CIDRAM can cache there, instead of using flat files.
Once those two things have been done, I'll probably start recommending for people to switch to one of the other cache options, to avoid these kinds of problems. Not needing to track an ID counter anymore would mean far less read/write operations to the cache (in theory, we could enable logging, and still wouldn't need to do so for every blocked request, when we don't need to worry about tracking an ID counter), would mean that if it resets, that it won't affect entry IDs anymore, and using one of the other caching options would mean far less read/write operations to writable flat files. So, we have a possible plan there for how to resolve this, I think.
Related: https://github.com/CIDRAM/CIDRAM/issues/128#issuecomment-501995522
TL;DR: I know the downsides, but I think the problem of cache data disappearing and ID numbers resetting probably outweighs the downsides at this point, enough so that something should be done. Anyway.. creating this issue to track progress, provide an avenue to discuss it further, etc.
So.. I've been working on this over the past hour and a bit. Generating some basic sample IDs (attached below) using the code that I've come up with thus far.. What do you think, in terms of aesthetic (i.e., readable, not overbearing, but still somewhat useful), in terms of having suitable precision, etc? (Better to sort out any conceptual problems before I create any PRs or push any commits, I think).
Attached sample IDs can be broken up into three parts (like AAAAAAAAAA-BBBBBB-CCCCCCCCCC), where:
AAAAAAAAAA is the seconds component of the return value of microtime() (basically the same as the current Unix time; should be 10 digits).BBBBBB is the microseconds component of the return value of microtime() (normalised to 6 digits; preceding zeroes added when total microseconds elapsed since seconds is less than 1e+5).CCCCCCCCCC is the last 10 digits (nanoseconds part + smallest unit of the seconds part) of the return value of hrtime(true) (when hrtime() is defined and available; i.e., for PHP => 7.3). When hrtime() isn't defined and available (i.e., for PHP < 7.3), but random_int() is defined and available (i.e., for PHP => 7.0), CCCCCCCCCC will be populated by a random_int() integer between 1e+9 and (1e+10)-1. When random_int() also isn't defined and available (i.e., for PHP < 7.0; this should only affect CIDRAM v1 users, seeing as CIDRAM v2 requires PHP >= 7.2 anyway), it'll fall back to rand() (which isn't so great or useful, but at least pads it so that the length doesn't look too weird).Environment where the samples were generated: PHP 7.3.4, Windows 10 Home 64-bit.
1561483568-019824-6446675953
1561483568-019831-6446683362
1561483568-019839-6446690202
1561483568-019845-6446696471
1561483568-019851-6446702171
1561483568-019857-6446709580
1561483568-019864-6446715280
1561483568-019870-6446721549
1561483568-019876-6446727249
1561483568-019882-6446732948
1561483568-019888-6446738648
1561483568-019893-6446744918
1561483568-019900-6446750617
1561483568-019905-6446756317
1561483568-019911-6446762016
1561483568-019917-6446767716
1561483568-019922-6446773415
1561483568-019928-6446779115
1561483568-019934-6446784245
1561483568-019939-6446789944
1561483568-019945-6446795644
1561483568-019950-6446801343
1561483568-019956-6446807043
1561483568-019962-6446812742
1561483568-019967-6446818442
1561483568-019973-6446824142
1561483568-019978-6446829271
1561483568-019984-6446834971
1561483568-019990-6446840670
1561483568-019995-6446846370
1561483568-020001-6446852069
1561483568-020006-6446857199
1561483568-020012-6446862899
1561483568-020018-6446868598
1561483568-020023-6446874298
1561483568-020029-6446879997
1561483568-020035-6446885697
1561483568-020040-6446891396
1561483568-020046-6446897096
1561483568-020051-6446902226
1561483568-020057-6446907925
1561483568-020063-6446913625
1561483568-020068-6446918754
1561483568-020073-6446924454
1561483568-020079-6446930154
1561483568-020085-6446935853
1561483568-020090-6446941553
1561483568-020096-6446946682
1561483568-020101-6446952382
sorry about delay, been thinking about this .....
-- I am not convinced the ID number achieves any really useful user purpose
-- these numbers are not easily readable, maybe take some parts of A, B and C to give uniqueness, at least in displays
-- I use the ID number to monitor the number of blocks so far to day. maybe you could provide this in another way?
having said all that, if the idea stops cache resetting, then it looks like a relatively easy solution with little downside, if you could make the number more readable.
I use the ID number to monitor the number of blocks so far to day. maybe you could provide this in another way?
There are logging frameworks which read line for line and count the matching lines.
Generally a timestamp value is generic and safe to store. Otherwise you might want to format this to some datetime string but the representation depends on your timezone and so on.
Log rotation might make it easier for you (I have recommended monolog for CIDRAM and phpMussel very early in the development). This allows you to easily format your logs as needed (for read / write). It is also battle tested and has many storage adapters.
thanks Daniel - good ideas
I think I can fix this easily with file(); and count().
I already have daily logs so data volumes are small
I do not want to sound negative about this but the new IDs (apart from the fixed issues) what purpose do they serve ? I mean what use have for us the webmasters ?
Previously we were able to search, make a note, see how many blocks we had, etc etc.
Now it is impossible.
Previously we were able to search, make a note, see how many blocks we had, etc etc.
You can still do this. Either use a log parser like Apache Logs Viewer or another one, use daily rotated logs (highly recommended) or add some metadata like the formatted date string (we might make the format customizable).
What it solves? Race conditions, ID collisions, more granular reporting using the time values, possibly also some file locking / deadlock issues which result in race conditions, no problematic resets if cache or anything else is deleted / corrupted, ...
In the frontend and on the filesystem you can still parse the information.
Most editors also count lines and doing a count() is also possible.
I just now saw this issue, but made my response at Gitter. Also, if this new counter requires PHP 7.3 that would be impossible for me atm since phpBB can only use up to 7.2 right now with phpBB 3.2.7. I think it won't be until phpBB 3.3.x is released will it support PHP 7.3.
Although the suggested format adds granularity and possibly solves some race conditions, it is not and will not be the ultimate solution to the issue with the counter.
It does not solve every kind of race condition under high load, at least not without an active caching scheme in place.
What it does is destroying readability for humans, especially the kind that might need to complain about a block.
"I got blocked, it was some long number starting at 1561483, can you fix it?"
What it does is destroying readability for humans, especially the kind that might need to complain about a block.
Not really, we can hash that.
Also, if this new counter requires PHP 7.3
It does not require PHP 7.3.
Also, if this new counter requires PHP 7.3
It does not require PHP 7.3.
Okay, thanks. I couldn't really understand what was being said.
Yeah, I don't think I like the idea of strings of numbers I'll have a hard time decoding.
sorry about delay, been thinking about this .....
No problem at all. Two days later, and I'm in the same boat (delayed reply), due to being caught up with other things until now (my bad!). It happens. '^.^
I appreciate the feedback from everyone, regardless.
I do not want to sound negative about this but the new IDs (apart from the fixed issues) what purpose do they serve ? I mean what use have for us the webmasters ?
No problem. If unsure about something, it's good to ask. :-)
Generally, IDs provide (in theory) a way to refer to a specific block event or log entry. But, in order to do that effectively, these IDs should be as unique as possible (which is why a resetting cache, and thus a resetting ID counter, posed a problem; if the ID counter could reset, there would be no way to guarantee uniqueness). Getting rid of the counter entirely (thus avoiding the need to use the cache to generate log entry IDs), would solve that particular problem. But, if we don't use a counter to generate IDs, we would need something else (which is one of the reasons why the numbers are now a bit longer, as they're using microtime and high resolution time, or randomly generated values instead of high resolution time when high resolution time isn't available). Ideally though, we don't want them to become completely unreadable in the process, too.
As an example situation where the IDs might become useful: A user complains about being falsely blocked (a false positive), doesn't know why they were blocked, and demands that we tell them why they were blocked. If they were blocked due to their IP address being covered by a CIDR signature or auxiliary rule, we could usually just ask for their IP address to be able to properly diagnose the problem. But, if they were blocked for some other reason, such as a user agent, hostname, or referrer covered by a module signature, and if they also happen to be on a network that rapidly changes a user's assigned IP address every few minutes or so (happens sometimes with cheaper mobile providers, VPNs, certain kinds of NAT'd networks, low-end metropolitan networks through Asia and South America, etc), or if a particular CIDRAM installation fully anonymises logged IP addresses, then asking for an IP address mightn't be sufficient to be able to properly diagnose the problem. In such cases, we could ask the user to tell us what ID they see on the page when they're blocked. Because IDs are unique, the ID they see should correspond to exactly one, specific log entry. As soon as we've found that specific log entry in our logs, we can begin analysing that log entry to try to diagnose the problem, attempt to cross-reference it against similar log entries if needed and so on.
Yeah, I don't think I like the idea of strings of numbers I'll have a hard time decoding.
The explanation included with the sample IDs I provided earlier, is mostly intended to share (and provide a way to test, and possibly refine, in case my current thinking about the problem has gone in a wrong direction without my realising it, which is always possible, as nobody is perfect, after all) about how I rationalised generating them in the first place, and in order to explain how I rationalised generating them in the first place, I needed to also explain how the proposed generation process worked. But, in terms of being able to decode IDs: In the contexts where IDs would be useful or needed, we don't really need to decode anything, and don't actually need to know any of the information given by the explanation included with the sample IDs. Generally, we would just need to know to tell users to copy/paste IDs to give them to us when we need them, to help diagnose possible false positives, if/when they complain about being falsely blocked (so, these users might ask us, "ID? What are you talking about? What's this 'ID' thing look like?", and we could tell them, "on the page, you should see a label, 'ID:', with a number after it; the 'ID' I'm talking about is that number").
TL:DR; Decoding isn't really a problem. But, readability is still something we want to maintain, if at all possible (in the sense that we don't want people, upon seeing an ID, to think "what the hell is that?!", and possibly panic that the situation is worse than it really is, or that something is going on that isn't actually going on. Also, if we're going to call it a number, it would obviously still need to actually look like a number, otherwise people would definitely be confused; or, if it looks like something else, we would need to know what else to call it, so that everyone involved in the discussion can have the same understanding about what we're all talking about.
What it does is destroying readability for humans, especially the kind that might need to complain about a block.
"I got blocked, it was some long number starting at 1561483, can you fix it?"
Yeah.. That was my main concern when first coming up with it, too. There are many people out there that, as soon as they see any kind of number or string more than a few characters long, just kind of shut down over it ("in one ear, out the other", or "see everything; remember nothing").
I know some people like that in person, that often ask me for help with things, like "how do I access Facebook?", or "can you show me again how to download this email?", and usually the same things, over and over again, every time. Frustrates the hell out of me, but not much I can do about it, so I tolerate it. For basic things like Ctrl+C/Ctrl+V copy/paste in a word processor, for example, I've said before, "write it down, so that you remember", and they'll write it down (sometimes, anyway), but then they'll still ask me about it again in the future anyway. I'll ask then, "didn't you write it down last time?", and they'll say that they did, but had forgotten they'd written it down, so didn't look in their notebook first.
TL:DR; -- Undoubtedly, the "it was some long number starting at 1561483, can you fix it?" scenario, will happen at some point or another.
(Theoretically could happen with the old system too, if the counter survived long enough to grow big enough to end up being a similar size, but unlikely to happen in practice, due to the problems that inspired this change in the first place likely killing it before it reaches that size anyway).
So, the question then, is what can we do to improve the system, or to help alleviate the risk of those kinds of scenarios. Any ideas (from anyone)? '^.^
see how many blocks we had, etc etc.
We can still find out how many blocks we've had by looking at the statistics page (assuming statistics have been enabled for a particular installation). But, unlike the new way of generating IDs, those statistics still rely on caching, and we can't really change that so easily (if we're going to actually record statistics somehow.. the keyword there, being "record"). So, the statistics page would (in theory) still be subject to possible race conditions and a resetting cache.
Hopefully, when I can find time to finish documenting the supplementary cache options properly, some of those supplementary cache options will prove useful for at least a few users, in terms of these problems.
(Or, for any users that haven't experienced a cache reset yet.. maybe they won't need to worry about these problems, and using the statistics page, as it currently is, will be sufficient for them. Case by case, I guess).
ideas on ID numbers
I dont believe the number that is displayed needs to be totally unique. The number on file can be whatever. The number displayed in blocks and logs can be a meaningful subset a lot shorter than currently.
For my purposes someone contacts me saying ID xxxx was blocked yesterday or similar. I never get it was blocked last month, and they will normally provide the date, or I ask for it.
so the number needs to be unique for me within the last week.
if you want to look it up in a monthly log, there there are not going to be a lot of duplicates given some form of microsecond / nanosecond component. And you normally know what day you want anyway.
statistics reset this afternoon, nothing in the error log, at that time. Just a couple of normal GETS processed with no error. A lot of GETS opening sessions at the same time, but not calling CIDRAM.
another stats reset yesterday afternoon. 2 X HEAD received at the same time from Russia, both blocked, and stats reset
(Just to make it known: I've read the most recent replies here, since my last reply, so I'm up to date. Just haven't replied again yet because I'm not sure how to push forward further on this yet. Thinking on it, and will reply again when I figure something out).
I was wondering if I contributed to these problems on my site. End of April I switched hosting services which I did by installing the latest CIDRAM, and then copying the config.ini from production. This was from a version that was a few weeks old. Could this be causing a problem ?
CIDRAM's ini configuration file should, by design, be transferable between installations, so I definitely don't think that'd be the problem. When transferring an ini configuration file between different versions of CIDRAM, any configuration directives newly added to CIDRAM since the version that the configuration file originally came from, should be automatically assumed by the newer version from the configuration defaults file (which holds the default values for any and all configuration directives supported at the time), meaning that missing configuration directives shouldn't have any effect on the new installation, and if the configuration file happens to contain any deprecated or removed configuration directives, those'll generally just be ignored anyway, and so shouldn't have any effect at all.
(That all said, I'm still pretty stumped about the resets, disappearing files and so on, so bouncing off whatever theories that any of us can come up with with each other, certainly won't do any harm at all).
well its been all quiet for 10 days - 3 GETS from a bot all received within a second this morning. Stats reset and IP history lost.
So there is still some issue with getting the lock on a file and overwriting / recreating the whole file?
Or is the fole not opened in "append only" mode @Maikuolan?
it is happening more frequently, maybe since I changed hosting suppliers.
maybe things are not getting processed as quickly which is causing this
problem once CIDRAM is hit with repeated short term blocks
regards .. Mike
On 16/07/2019 11:02, Daniel Ruf wrote:
>
So there is still some issue with getting the lock on a file and
overwriting / recreating the whole file?
Or is the fole not opened in "append only" mode @Maikuolan
https://github.com/Maikuolan?—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/CIDRAM/CIDRAM/issues/131?email_source=notifications&email_token=AGIKBL66VOZ5IUFVSRHIJALP7WMCPA5CNFSM4H3EZJ6KYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD2ALQBI#issuecomment-511752197,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AGIKBL6WNCYUPJHRVZAWSQDP7WMCPANCNFSM4H3EZJ6A.
So there is still some issue with getting the lock on a file and overwriting / recreating the whole file?
Or is the fole not opened in "append only" mode @Maikuolan?
For the default flatfile caching, rb is used for reading and wb for writing.
if ($this->FFDefault) {
if (is_file($this->FFDefault)) {
if (is_readable($this->FFDefault) && is_writable($this->FFDefault)) {
$this->Using = 'FF';
if (!$Filesize = filesize($this->FFDefault)) {
$this->WorkingData = [];
return $this->Modified = true;
}
$Data = '';
$Handle = false;
$Start = time();
while (true) {
$Handle = fopen($this->FFDefault, 'rb');
if ($Handle !== false || (time() - $Start) > self::FLOCK_TIMEOUT) {
break;
}
}
if ($Handle === false) {
return false;
}
$Locked = false;
while (true) {
if ($Locked = flock($Handle, LOCK_EX | LOCK_NB) || (time() - $Start) > self::FLOCK_TIMEOUT) {
break;
}
}
if (!$Locked) {
fclose($Handle);
return false;
}
$Size = ($Filesize && self::BLOCKSIZE) ? ceil($Filesize / self::BLOCKSIZE) : 0;
$Step = 0;
while ($Step < $Size) {
$Data .= fread($Handle, self::BLOCKSIZE);
$Step++;
}
flock($Handle, LOCK_UN);
fclose($Handle);
$Data = $Data ? unserialize($Data) : [];
$this->WorkingData = is_array($Data) ? $Data : [];
return true;
}
} else {
$Parent = dirname($this->FFDefault);
if (is_dir($Parent) && is_readable($Parent) && is_writable($Parent)) {
$this->WorkingData = [];
$this->Using = 'FF';
return $this->Modified = true;
}
}
return false;
}
(In the above reading excerpt, when false is returned, PHP should die the request with the L10N string Error_WriteCache, thus effectively preventing the write procedure from ever triggering).
if ($this->FFDefault && $this->Modified && $this->Using === 'FF') {
$Handle = false;
$Start = time();
while (true) {
$Handle = fopen($this->FFDefault, 'wb');
if ($Handle !== false || (time() - $Start) > self::FLOCK_TIMEOUT) {
break;
}
}
if ($Handle === false) {
return;
}
$Locked = false;
while (true) {
if ($Locked = flock($Handle, LOCK_EX | LOCK_NB) || (time() - $Start) > self::FLOCK_TIMEOUT) {
break;
}
}
if ($Locked) {
fwrite($Handle, serialize($this->WorkingData));
flock($Handle, LOCK_UN);
}
fclose($Handle);
}
(Some things to note though: My above reply relates only to the default flatfile caching, which is responsible for handling things like statistics, IP tracking information, etc. Things like the standard block event logging use append only, and are handled by a different part of the codebase. Also, although I've linked to the v2 branch in my above reply, that particular part of the codebase is currently exactly the same between v1 and v2, so there shouldn't theoretically be any behavioural differences between v1 and v2 in regards to flatfile caching at this time).
from what is happening is it worth checking to make sure multi thread writing is working properly ?
from what is happening is it worth checking to make sure multi thread writing is working properly ?
Problem is, that individual instances of PHP, in most cases, aren't generally aware of each other when it comes to things like file access and locking (which is why race conditions tend to be such a common and tedious problem when it comes to reading/writing files using PHP where multiple instances of PHP are running).
(To tie this back into the original subject matter of this issue though: In such cases, using a mechanism entirely independent of reading/writing files of any kind is generally a more reliable way to come up with unique numbers/IDs/etc, which is why we were looking at this for generating block event IDs, instead of using counters anymore).
For any users that might he wondering now, whether they could just get rid of IDs entirely (i.e., not seeing any purpose in them anymore, and thinking that they might be unnecessary now): The proposal I made at https://github.com/CIDRAM/CIDRAM/issues/139#issuecomment-513439942 would (eventually.. when the time comes to implement it, which shouldn't be for a while yet though) provide a means to do that.
I see you are using flock() - I havent passed this way before in any detail, but isnt this supposed to achieve what you want ?
In theory, yes. In practice though.. not always. I've had some users report that they're seeing behaviour which, put simply, shouldn't be happening at all, and I don't entirely understand yet (like where the cache, and also sometimes logs, seem to just disappear entirely, deleted for whatever reason), but I suspect might be because of too many concurrent access attempts being made to the files in question at the same time (not confirmed though). There's also the problem that PHP requires that a file be already opened before a lock can be acquired, which can occasionally lead to some weirdness when multiple instances of PHP both successfully open the same file at the same time, and then both try to acquire an exclusive lock onto that same file. Still.. it's better than nothing (i.e., better to use flock when writing to files than to not use it), and prevents these kinds of problems (when it's used correctly, at least) most of the time.
I see what you mean, been reading the comments in the php manual
this is interesting, http://cubicspot.blogspot.com/2010/10/forget-flock-and-system-v-semaphores.html
it uses fopen 'x' to make the system create your own lock. It only creates a file if it doesnt already exist.
Stats reset again last night. Odd thing this time there were no blocks at the time of the reset. It looks like there were 3 valid and duplicate requests all received at the same time.
stats just reset again.
slightly unusual as they were 6 x HEAD, all received at the same time, from the same IP with no UA, so they were blocked, but I guess because they were HEAD, were not reported as blocks by CIDRAM.
Though they all got 403.
shall I continue reporting these events ?
Will get back to you on this shortly. Need to think about it for a bit.
Will get back to you on this shortly. Need to think about it for a bit.
Sorry for the delay. Been working on some other things.
this is interesting, http://cubicspot.blogspot.com/2010/10/forget-flock-and-system-v-semaphores.html
Definitely an interesting approach. I can see how it would work (and principally, out of frustration, due to system locking mechanisms not working properly, I could see situations where I'd be tempted to use the same approach), but I'm not super comfortable that needing to write, read, and delete multiple files, unconditionally, for every single request, just in order to ensure a slightly more reliable lock, is necessarily the ideal way to go here either. Even for the current flatfile cache system that CIDRAM uses, the cache file should only ever be written to when there are actual changes to the cache (new cache entries, old cache entries expiring, adding to the statistics, etc).
Semaphores would be an interesting approach too, but if they aren't actually supported across all major operating systems, they wouldn't serve well as default baseline for CIDRAM's cache system (due to that it could then just outright prevent caching from working at all in certain environments where they aren't supported).
I'd considered even possibly using different methods for different systems, to leverage whatever works best for each particular major operating system, but doing that would add a great deal of complexity to the whole thing too, and increase the risk that bugs might emerge in the future that I won't find so easy to diagnose or fix. To avoid adding too much complexity, it would be ideal if we could avoid adding OS-dependent behaviour wherever possible (so that everything, at least in theory, uses the same logic and everything else, regardless of the operating system used).
At the most extreme end of possible solutions.. After PHP 7.4 is released, I could try using FFI to work around some of the shortfalls of PHP's own, internal file/stream read/write functions (not really making a serious suggestion.. just sharing thoughts..), but.. that would also be introducing a whole new level of risk for things potentially going wrong (because FFI is basically writing things at C level, which.. is better to avoid, if it isn't needed). It would also be locking the relevant affected future versions to PHP 7.4 (and it's definitely a bit too early to be doing that just yet).
Anyway.. to answer:
shall I continue reporting these events ?
Probably not much point anymore, I think. It's pretty clear at this point what's happening.. We just don't yet have a reliable solution for what's happening (for flatfile caching, at least). :-/
Considering that this problem seems to be affecting yours far more often than anyone else's, it might be worth switching to PDO for your particular installation, so that you'll be able to just get away from flatfile caching entirely. I'll make a start on documenting how to do that shortly and let you know once it's done.
Anyway, seeing as the main subject of this particular issue, "improve how CIDRAM determines entry IDs", has been resolved now (the new way to determine entry IDs having been implemented now for a while), I think I should mark this issue accordingly and close it.
Most helpful comment
thanks Daniel - good ideas
I think I can fix this easily with file(); and count().
I already have daily logs so data volumes are small