Uncaught Error: Call to a member function setTimezone() on bool in /usr/share/icingaweb2/modules/icingadb/library/Icingadb/Common/ObjectInspectionDetail.php:240

[dwt]

Hi there,

on the current docker containers (that is from 2021-11-22) when clicking on a failed check and trying to check out 'Source' - this stack trace occurs:

Uncaught Error: Call to a member function setTimezone() on bool in /usr/share/icingaweb2/modules/icingadb/library/Icingadb/Common/ObjectInspectionDetail.php:240
Stack trace:
#0 [internal function]: Icinga\Module\Icingadb\Common\ObjectInspectionDetail->formatTimestamp()
#1 /usr/share/icingaweb2/modules/icingadb/library/Icingadb/Common/ObjectInspectionDetail.php(286): call_user_func()
#2 /usr/share/icingaweb2/modules/icingadb/library/Icingadb/Common/ObjectInspectionDetail.php(101): Icinga\Module\Icingadb\Common\ObjectInspectionDetail->createNameValueTable()
#3 /usr/share/icingaweb2/modules/icingadb/library/Icingadb/Widget/Detail/HostInspectionDetail.php(15): Icinga\Module\Icingadb\Common\ObjectInspectionDetail->createLastCheckResult()
#4 /usr/share/icinga-php/ipl/vendor/ipl/html/src/HtmlDocument.php(295): Icinga\Module\Icingadb\Widget\Detail\HostInspectionDetail->assemble()
#5 /usr/share/icinga-php/ipl/vendor/ipl/html/src/HtmlDocument.php(496): ipl\Html\HtmlDocument->ensureAssembled()
#6 /usr/share/icinga-php/i

#0 [internal function]: Icinga\Application\Web->Icinga\Application\{closure}()
#1 {main}

This code seems faulty (though it looks good).

Any idea what is happening? Do I have a missing configuration or is that code wrong?

[lippserd]

Which version of Icinga 2 are you using?

[dwt]

I'm not entirely sure what the best way to report that would be.

Icinga itself reports at /about that it is:

Icinga Web 2 Version
2.9.5
Git Commit
3df684bcdfa516323e5a03abedc353771d7b3c9f
PHP Version
7.4.25
Git Commit Datum
2021-11-17
Copyright
© 2013-2021 Icinga GmbH

Does that help?

[dwt]

The executed in the container looks the same as the code I linked, changing it to this at least allow me to see the service details:

    private function formatTimestamp($ts)
    {
        if (empty($ts)) {
            return new EmptyState(t('n. a.'));
        }

        if (is_float($ts)) {
            $dt = DateTime::createFromFormat('U.u', $ts);
        } else {
            $dt = (new DateTime())->setTimestamp($ts);
        }
        return 'fnord';;

        return $dt->setTimezone(new DateTimeZone('UTC'))
            ->format('Y-m-d\TH:i:s.vP');
    }

[lippserd]

I meant the Icinga 2 (not Web) version.

[dwt]

Is this helpful?

% docker compose exec icinga2 bash
icinga@ops:/$ icinga2 --version
icinga2 - The Icinga 2 network monitoring daemon (version: r2.13.0-1)

Copyright (c) 2012-2021 Icinga GmbH (https://icinga.com/)
License GPLv2+: GNU GPL version 2 or later <https://gnu.org/licenses/gpl2.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

System information:
  Platform: Debian GNU/Linux
  Platform version: 10 (buster)
  Kernel: Linux
  Kernel version: 5.10.47-linuxkit
  Architecture: x86_64

Build information:
  Compiler: GNU 8.3.0
  Build host: 59c8b79036b2
  OpenSSL version: OpenSSL 1.1.1d  10 Sep 2019

Application information:

General paths:
  Config directory: /etc/icinga2
  Data directory: /var/lib/icinga2
  Log directory: /var/log/icinga2
  Cache directory: /var/cache/icinga2
  Spool directory: /var/spool/icinga2
  Run directory: /run/icinga2

Old paths (deprecated):
  Installation root: /usr
  Sysconf directory: /etc
  Run directory (base): /run
  Local state directory: /var

Internal paths:
  Package data directory: /usr/share/icinga2
  State path: /var/lib/icinga2/icinga2.state
  Modified attributes path: /var/lib/icinga2/modified-attributes.conf
  Objects path: /var/cache/icinga2/icinga2.debug
  Vars path: /var/cache/icinga2/icinga2.vars
  PID path: /run/icinga2/icinga2.pid

[dwt]

Inspecting the code further, the timestamps are stuff like 1637595226.352355, but DateTime::createFromFormat('U.u', $ts) converts that to false. I don't pretend to understand PHP, but afaik you are missing some error handling there?

[lippserd]

No, Icinga DB requires Icinga 2.13.2.

[lippserd]

Icinga DB (RC2) should not run at all in your setup.

[dwt]

Not quite sure what I'm doing wrong here - AFAIK I'm on the current docker containers as of today icinga/icinga2:master Is there a different - newer image that I can be using? I'll go check now to see that this is indeed using the images I pulled today from docker hub.

[dwt]

One

docker compose stop
docker compose rm -f
docker compose pull
docker compose up

later, with this configuration https://github.com/dwt/docker-compose-icinga (derived from your docker compose file)

I'm still getting icinga version r2.13.0-1. Still investigating

[lippserd]

Can you try this? lippserd/docker-compose-icinga#16

[lippserd]

I would do the following in order to recreate the setup:

docker-compose down --volumes && docker-compose pull && docker-compose up --build -d

[dwt]

After re-checking, I'm now fairly sure I'm running this image: https://hub.docker.com/layers/icinga/icinga2/master/images/sha256-fce8b596d0554de8397cbdb37b0c986848a6f9fb76222116c7e865072622733e?context=explore - which AFAIK is the current master image of icinga. Is that representing an old version?

If I get you correct, icinga2:master is too old to work correctly with icingadb-web? I will have time tomorrow to look into the pull request you provided and get that working.

[lippserd]

Correct icinga2 --version output looks like that:

docker run --rm icinga/icinga2:master icinga2 --version
...
icinga2 - The Icinga 2 network monitoring daemon (version: v2.13.1-57-g31c4ba31b)
...

[lippserd]

My PR uses the latest tag (default) instead of master so that the latest release versions are used. If you continue to have problems, please head over to the forums.

[dwt]

Well, I was switching to master, to check out features implemented after bug reports I raised. Then everything kind of deteriorated. I will try switching back to :latest for further experiments if possible.

[lippserd]

I understand but your master image is not really the master image 😆

[dwt]

Well, I do find that kind of confusing. I would have guessed that an image called :master kind of represents the master branch... Is there some documentation you guys maintain which images to use to get what from the repos?

[lippserd]

I don' think that this is our problem. Your image reports 2.13.0. But a fresh pull reports the following: #462 (comment)

[dwt]

I think I'm starting to see ghosts. This is the latest image I can see linked from docker hub

When I pull that with this command:

docker pull icinga/icingaweb2:master@sha256:fce8b596d0554de8397cbdb37b0c986848a6f9fb76222116c7e865072622733e

It tells me it succeeded.

When I then run this with:

docker run --rm icinga/icingaweb2:master@sha256:fce8b596d0554de8397cbdb37b0c986848a6f9fb76222116c7e865072622733e icinga2 --version
...
icinga2 - The Icinga 2 network monitoring daemon (version: r2.13.0-1)

I get this ridiculously (?) old version.

How am I not running the latest published image from docker hub? Am I completely misunderstanding how docker works here?

[dwt]

Well, seems I am running the latest code, even if it doesn't look it. So maybe the PHP code to do the date formatting does actually have a bug?

[lippserd]

Sorry, I was not aware of this version display bug. What versions of Icinga DB and Icinga DB Web are you using?

[dwt]

I am on the current :master images of each of them from today on docker hub. Specifically I am on these images:

dwt@nathan ~/Code/Projekte/sntl/opensource/icinga (git)-[master] % docker compose ps --format json|jq '.[] | {ID, Name}'                                        :(
{
  "ID": "b8458df07ab885983eedbc7fd704435a9aae493414e49831eea76fe91557699f",
  "Name": "icinga_icinga2_1"
}
{
  "ID": "cde298342b19379920e8b53859e1686ab6d48508c454c0977d9e99b4c575ad24",
  "Name": "icinga_icingadb_1"
}
{
  "ID": "a7e459cfe3e5b72eec4ee70997517c3f013280cba81e0cb97c9253cf3a37ec1d",
  "Name": "icinga_icingaweb_1"
}

% docker inspect b8458df07ab885983eedbc7fd704435a9aae493414e49831eea76fe91557699f | jq '.[] | {ID, Image, image: .Config.Image, Name}'
{
  "ID": null,
  "Image": "sha256:98e2c96fba9b860d694e763432b55d27fa7622da028e712cd04470f01f484b17",
  "image": "icinga/icinga2:master",
  "Name": "/icinga_icinga2_1"
}
% docker inspect 98e2c96fba9b860d694e763432b55d27fa7622da028e712cd04470f01f484b17 | jq '.[] | {Id, RepoTags, RepoDigests}'       
{
  "Id": "sha256:98e2c96fba9b860d694e763432b55d27fa7622da028e712cd04470f01f484b17",
  "RepoTags": [
    "icinga/icinga2:master"
  ],
  "RepoDigests": [
    "icinga/icinga2@sha256:ea0b40298f62e93ecb2511e27289a5c20d8e11e752f769306761f908b68ebe29"
  ]
}


% docker inspect cde298342b19379920e8b53859e1686ab6d48508c454c0977d9e99b4c575ad24 | jq '.[] | {ID, Image, image: .Config.Image, Name}'
{
  "ID": null,
  "Image": "sha256:2cbf7367a1f56cc9adb1a54b950a18ffadd77a04f3d16ae07609d29535692e30",
  "image": "icinga/icingadb:master",
  "Name": "/icinga_icingadb_1"
}
% docker inspect 2cbf7367a1f56cc9adb1a54b950a18ffadd77a04f3d16ae07609d29535692e30 | jq '.[] | {Id, RepoTags, RepoDigests}'
{
  "Id": "sha256:2cbf7367a1f56cc9adb1a54b950a18ffadd77a04f3d16ae07609d29535692e30",
  "RepoTags": [
    "icinga/icingadb:master"
  ],
  "RepoDigests": [
    "icinga/icingadb@sha256:baa9cb297801a1d298b5754567ce86cc789430262989233f476523af2e8ef645"
  ]
}

% docker inspect a7e459cfe3e5b72eec4ee70997517c3f013280cba81e0cb97c9253cf3a37ec1d | jq '.[] | {ID, Image, image: .Config.Image, Name}'
{
  "ID": null,
  "Image": "sha256:26df2026d212d8c6cc7e0800739e7928ff8730416444e06754df2f7397765e01",
  "image": "icinga/icingaweb2:master",
  "Name": "/icinga_icingaweb_1"
}
% docker inspect 26df2026d212d8c6cc7e0800739e7928ff8730416444e06754df2f7397765e01 | jq '.[] | {Id, RepoTags, RepoDigests}'
{
  "Id": "sha256:26df2026d212d8c6cc7e0800739e7928ff8730416444e06754df2f7397765e01",
  "RepoTags": [
    "icinga/icingaweb2:master"
  ],
  "RepoDigests": [
    "icinga/icingaweb2@sha256:d97d7181fe701058fb20cdd0be4e4db158aae501a6b9c27fb9eb5c33fac4ba3a"
  ]
}

They self-identify as:

% docker compose exec icinga2 icinga2 --version
icinga2 - The Icinga 2 network monitoring daemon (version: v2.13.0-118-gc4c51a2b5)
% docker compose exec icingaweb cat /usr/share/icingaweb2/VERSION
v2.9.5

I have no clue how to get the version out of icingadb. :-(

Does that help?

[yhabteab]

There was a similar bug in the past and it has already been fixed #242. Can you please var_dump($ts);die; and share the output here? DateTime::createFromFormat() is returning false probably for some reason.

[lippserd]

@yhabteab I think the error is due to a millisecond timestamp.

@dwt icingadb --version or -v should print the version.

[lippserd]

@dwt Did you start with fresh Volumes for Redis and MySQL?

[dwt]

@yhabteab I think the error is due to a millisecond timestamp.

That would be unsurprising - and mean missing error handling.

@dwt icingadb --version or -v should print the version.

% docker compose exec icingadb ./icingadb --version
Icinga DB version: v1.0.0-rc2-dev

Yes, yesterday - not today. I'll try it again after I have reported the output of @yhabteab asked for.

[dwt]

@yhabteab I have modified the code to this:

private function formatTimestamp($ts)
{
    if (empty($ts)) {
        return new EmptyState(t('n. a.'));
    }

    if (is_float($ts)) {
        $dt = DateTime::createFromFormat('U.u', $ts);
        if ( ! $dt ) {
            var_dump($ts); var_dump($dt); die;
        }
    } else {
        $dt = (new DateTime())->setTimestamp($ts);
    }

    return $dt->setTimezone(new DateTimeZone('UTC'))
        ->format('Y-m-d\TH:i:s.vP');
}

For me this creates this output:

float(1637671791,1335) bool(false)

Which is surprising, as it looks completely benign?

[dwt]

Might there be some kind of localization issue at play and php represents the float with a ',' instead of a '.' as is expected by the formatting function?

[dwt]

@lippserd yes, starting with fresh volumes, the issue is still reproducible.

[lippserd]

Might there be some kind of localization issue at play and php represents the float with a ',' instead of a '.' as is expected by the formatting function?

That could be true but I don't know how 😆 Which language are you using for Web 2?

Could you try the following fix pls:

$dt = DateTime::createFromFormat('U.u', sprintf('%F', $ts));

Note the sprintf addition.

[dwt]

@lippserd that sprintf() seems to work.

The source now renders fine:

[nilmerg]

That could be true

Nah. It's var_dump that is adding the comma. It's clearly identifying it as float and not as string which it would be if there's really a comma involved.

DateTime::createFromFormat('U.u', 1637671791.1335) is working fine.

that sprintf() seems to work.

That's weird. Maybe var_dump swallows some fractions off of the float? The u format identifier only supports up to 6 digits, not more. sprintf on the other hand reduces them by default to 2 if I'm not mistaken.

[lippserd]

Nah. It's var_dump that is adding the comma. It's clearly identifying it as float and not as string which it would be if there's really a comma involved.

But that clearly shows that it has to do with localization. DateTime::createFromFormat() creates a string representation from the float (here with a comma instead of a dot). While sprintf('%F', ...) always uses a dot.

Edit: Default is 6 digits for sprintf.

[dwt]

Hey, if you have any other ideas for experiments, I'll gladly run them for you.

Other than that: It seems that DateTime::createFromFormat() can return an error code and that this error code is ignored right now - so as first line of defence it seems prudent to handle it? Maybe by logging an error and what the input was and then falling back to returning the timestamp as is? It seems that this would be much better than just killing that part of the app?

[nilmerg]

Maybe by logging an error and what the input was and then falling back to returning the timestamp as is? It seems that this would be much better than just killing that part of the app?

Sorry, but for such small unexpected things error handling is just code smell. We'll fix the bug and no error handling is needed. The exception isn't bad, it's only just this single view that is affected. So unless the bug won't crash the webserver and lock out every user on the instance, I choose less code smell. 😉

[dwt]

@lippserd sorry, missed your question: 'Which language are you using for Web 2?' English I believe, nothing changed from the default config on the image. In my understanding Docker does not inherit any environment variable from the starting shell - especially using docker compose.

Checking the environment inside the container doesn't seem to expose anything LANG_* related that I could imagine getting through. Could it be that PHP interprets anything from the incoming requests? Because I am on a german system (MacOS 11.6.1 (20G224), Safari Version 15.1 (16612.2.9.1.30, 16612).

[dwt]

Environment in the container:

% docker compose exec icingaweb env 
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
HOSTNAME=c432b08bfc9a
TERM=xterm
icingaweb.modules.icingadb.redis.redis1.host=redis
icingaweb.resources.icingaweb_db.dbname=icingaweb
icingaweb.config.global.config_backend=db
icingaweb.resources.icingadb.password=Eiph4xohSho3oaghohN8
icingaweb.groups.icingaweb2.resource=icingaweb_db
icingaweb.resources.icingaweb_db.username=icingaweb
icingaweb.modules.monitoring.commandtransports.icinga2.username=icingaweb
icingaweb.modules.icingadb.redis.redis1.port=6379
icingaweb.modules.icingadb.commandtransports.icinga2.username=icingaweb
icingaweb.resources.icingadb.host=mysql
icingaweb.authentication.icingaweb2.resource=icingaweb_db
icingaweb.resources.icingaweb_db.host=mysql
icingaweb.resources.icingadb.charset=utf8mb4
icingaweb.modules.monitoring.commandtransports.icinga2.password=zoosais5aghat6meb2Di
icingaweb.config.global.config_resource=icingaweb_db
icingaweb.groups.icingaweb2.backend=db
icingaweb.modules.icingadb.commandtransports.icinga2.password=zoosais5aghat6meb2Di
icingaweb.resources.icingadb.db=mysql
icingaweb.modules.icingadb.commandtransports.icinga2.host=icinga2
icingaweb.modules.icingadb.commandtransports.icinga2.port=5665
icingaweb.modules.icingadb.config.icingadb.resource=icingadb
icingaweb.roles.Administrators.users=icingaadmin
icingaweb.modules.icingadb.config.redis1.host=redis
icingaweb.resources.icingaweb_db.charset=utf8mb4
icingaweb.authentication.icingaweb2.backend=db
icingaweb.resources.icingaweb_db.password=kahHiepolaidohfae0ie
icingaweb.resources.icingadb.username=icingadb
icingaweb.roles.Administrators.permissions=*
icingaweb.modules.monitoring.commandtransports.icinga2.host=icinga2
icingaweb.enabledModules=icingadb,ipl
icingaweb.passwords.icingaweb2.icingaadmin=teeh6waegei8RuRee5Bu
icingaweb.modules.icingadb.commandtransports.icinga2.transport=api
icingaweb.resources.icingaweb_db.db=mysql
icingaweb.resources.icingadb.dbname=icingadb
icingaweb.modules.monitoring.commandtransports.icinga2.transport=api
icingaweb.resources.icingadb.type=db
icingaweb.modules.icingadb.config.redis1.port=6379
icingaweb.resources.icingaweb_db.type=db
icingaweb.roles.Administrators.groups=Administrators
icingaweb.config.logging.log=php
HOME=/var/www

[dwt]

I am pretty confident that this is caused by an input from the request. Switching the browser languages around, i.e. 'Accept-Language: en-US,en;q=0.7,de;q=0.3' doesn't trigger the issue, while 'Accept-Language: de,en-US;q=0.7,en;q=0.3' does.

[dwt]

@nilmerg

Sorry, but for such small unexpected things error handling is just code smell. We'll fix the bug and no error handling is needed. The exception isn't bad, it's only just this single view that is affected. So unless the bug won't crash the webserver and lock out every user on the instance, I choose less code smell. 😉

Well, I'm not a PHP expert of course, but I have to say that I'm a bit confused by your perspective. Ignoring error codes is never a good thing, and a complex API like this that takes hidden inputs (it seems Localization plays a role here) - I am a bit lost why you would think of error checking as a code smell.

I mean, every error is unexpected - but to build robust software we still handle them because thats what it means to build robust software. That's why we have unit tests that check that we actually handle them, because otherwise it's just impossible to test that stuff by hand.

/rant over - of course this is your software, so you can do as you please. But collectively this missing check / bug has now cost us several hours of work time. (I don't even want to try to convert that into currency). I would like to make the argument that this is a pretty solid case that error checking (and then handling them!) complex and surprising functions from the PHP core library is a good idea.

[nilmerg]

Testing is the way to go. If I have a good/robust test, I'll find bugs and fix them, no need for error handling then. Granted, we don't unit test this part of the code. We did however ran many manual tests in the past and this issue never appeared. Some things just slip through. And it's still a release candidate, so you're also testing. 😉

Any error handling isn't code smell of course, only in this instance. What should we do instead here? Ignore the faulty value? Would you have opened this issue then? I guess not. Sometimes it's better that the user get's an exception, it's also easier for us to fix the issue then instead of having to ask for more and more details.

[dwt]

Well, if I had to code error handling in this case, several things come to mind:

1. Raise a exception that contains the input values in a way that allows users like me to open a meaningful bug report immediately. In the best case, that would have allowed an immediate bug report with all the details you guys need to debug this.
2. Fall back to a different formatting or no formatting at all and log the error. This would likely have maid the error invisible and I too like fail fast applications.

I would prefer option 1. as the old directive - if I can't handle an error, raise a good error message instead is always a good fallback.

[lippserd]

Dude this is a bug. There won’t be any error handling. Please stop this now.

[dwt]

Hi there, I was expecting to be able to test this bug fix in the latest image at some point - so far I'm still seeing this issue. Anything I'm doing wrong? Shouldn't this be auto released?

[nilmerg]

If you're talking about our docker images, icinga/icingaweb2:master is updated daily. Packages have not been updated since rc2.

[dwt]

@nilmerg that is what I'm trying - my understanding is that this image should contain the fix?

[nilmerg]

Unfortunately, no, the image also just uses the RC2, not the current master. (Icinga/docker-icingaweb2#62)