Internal Server Error when Org Admins view / populate events

[garrit-schroeder]

Questions	Answers
Type of issue	Bug, Question
OS version (server)	CentOS 7
OS version (client)	CentOS 7
PHP version	7.3.8
MISP version / git hash	2.4.112 hash of the commit - 3186b87
Browser	Firefox (does not concern)

Expected behavior

Org Admins can view / edit / populate events.

Actual behavior

Org Admins can not view / populate events. Other roles can!

Steps to reproduce the behavior

Create an Org Admin for an organization. Click on an event. Internal Server Error occurs.
When role of user is changed (to read-only, admin,..) event can be viewed and/or modified.

Logs, screenshots, configuration dump, ...

2019-08-20 11:50:54 Error: [PDOException] SQLSTATE[42S22]: Column not found: 1054 Unknown column 'AttributeTag.local' in 'where clause'
Request URL: /events/view/19635
Stack Trace:
#0 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Datasource/DboSource.php(502): PDOStatement->execute(Array)
#1 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Datasource/DboSource.php(468): DboSource->_execute('SELECT Attribu...', Array) #2 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Datasource/DboSource.php(715): DboSource->execute('SELECT Attribu...', Array, Array)
#3 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Datasource/DboSource.php(1564): DboSource->fetchAll('SELECT Attribu...', Array) #4 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Datasource/DboSource.php(1398): DboSource->_fetchHasMany(Object(Attribute), 'SELECT Attribu...', Array)
#5 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Datasource/DboSource.php(1411): DboSource->queryAssociation(Object(Attribute), Object(AttributeTag), 'hasMany', 'AttributeTag', Array, Array, true, Array, 1, Array)
#6 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Datasource/DboSource.php(1257): DboSource->queryAssociation(Object(Event), Object(Attribute), 'hasMany', 'Attribute', Array, Array, true, Array, 2, Array)
#7 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Model.php(3040): DboSource->read(Object(Event), Array)
#8 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Model/Model.php(3012): Model->_readDataSource('all', Array)
#9 /opt/appdir/http/MISP/app/Model/Event.php(2077): Model->find('all', Array)
#10 /opt/appdir/http/MISP/app/Controller/EventsController.php(1587): Event->fetchEvent(Array, Array)
#11 [internal function]: EventsController->view('19635')
#12 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Controller/Controller.php(499): ReflectionMethod->invokeArgs(Object(EventsController), Array)
#13 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Routing/Dispatcher.php(193): Controller->invokeAction(Object(CakeRequest))
#14 /opt/appdir/http/MISP/app/Lib/cakephp/lib/Cake/Routing/Dispatcher.php(167): Dispatcher->_invoke(Object(EventsController), Object(CakeRequest))
#15 /opt/appdir/http/MISP/app/webroot/index.php(92): Dispatcher->dispatch(Object(CakeRequest), Object(CakeResponse))
#16 {main}

SQL Query:

MariaDB [misp02]> describe attribute_tags;
+--------------+---------+------+-----+---------+----------------+
| Field | Type | Null | Key | Default | Extra |
+--------------+---------+------+-----+---------+----------------+
| id | int(11) | NO | PRI | NULL | auto_increment |
| attribute_id | int(11) | NO | MUL | NULL | |
| event_id | int(11) | NO | MUL | NULL | |
| tag_id | int(11) | NO | MUL | NULL | |
+--------------+---------+------+-----+---------+----------------+
4 rows in set (0,00 sec)

Might be in correlation to Issue #4658

Can an update to version 113 fix our issue?

Hope you guys can help us.

[iglocska]

It sounds like the upgrade to 112 failed or it didn't update the caches. Could you run the following?

Assuming MISP is installed in /var/www/MISP:

rm -f /var/www/MISP/app/tmp/cache/models/myapp*
rm -f /var/www/MISP/app/tmp/cache/persistent/myapp*

and then try again?

[garrit-schroeder]

Did that. Files reappeared shortly. But Issue sadly remains.

[iglocska]

Missed the output from MySQL, I see.

Could you run the following?

/var/www/MISP/app/Console/cake Admin setDatabaseVersion 35

After that clear the caches with

rm -f /var/www/MISP/app/tmp/cache/models/myapp*
rm -f /var/www/MISP/app/tmp/cache/persistent/myapp*

again and you should be sorted. Let me know if it didn't work!

[garrit-schroeder]

Just tried that. And the error is still there.
We narrowed down the problem a bit more. Events can not be opened if Attributes are present. As long as 0 attributes are added to an event we dont have a problem.

And i checked the database again. Schema has not changed on table attribute_tags.

Error Message in logs still the same.

[iglocska]

Could you check your audit logs in MISP?

Just log in as a site admin, go to audit logs, then select the update filter and paste the contents here.

Thanks!

[garrit-schroeder]

13579868 SYSTEM SYSTEM 2019-08-21 08:51:39 Server 0 update_database Issues executing the SQL query for 36 The executed SQL query was: ALTER TABLE attribute_tags ADD local tinyint(1) NOT NULL DEFAULT 0;
The returned error is: SQLSTATE[HY000]: General error: 1878 Temporary file write failure
13579860 SYSTEM SYSTEM 2019-08-21 08:51:05 Server 0 update_database Issues executing the SQL query for 36 The executed SQL query was: ALTER TABLE event_tags ADD local tinyint(1) NOT NULL DEFAULT 0;
The returned error is: SQLSTATE[42S21]: Column already exists: 1060 Duplicate column name 'local'
13445462 SYSTEM SYSTEM 2019-08-07 07:31:20 Server 0 update_database Issues executing the SQL query for 36 The executed SQL query was: ALTER TABLE attribute_tags ADD local tinyint(1) NOT NULL DEFAULT 0;
The returned error is: SQLSTATE[HY000]: General error: 1878 Temporary file write failure
13445459 SYSTEM SYSTEM 2019-08-07 07:30:37 Server 0 update_database Successfuly executed the SQL query for 36 The executed SQL query was: ALTER TABLE event_tags ADD local tinyint(1) NOT NULL DEFAULT 0;
13445448 SYSTEM SYSTEM 2019-08-07 07:30:36 Server 0 update_database Successfuly executed the SQL query for 35 The executed SQL query was: CREATE TABLE IF NOT EXISTS notification_logs (
id int(11) NOT NULL AUTO_INCREMENT,
org_id int(11) NOT NULL,
type varchar(255) COLLATE utf8_bin NOT NULL,
timestamp int(11) NOT NULL DEFAULT 0,
PRIMARY KEY (id),
KEY org_id (org_id),
KEY type (type)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin;

Thanks for your help. Appreciated

[iglocska]

How much empty space do you have? The alter tables fail probably because it cannot copy the table.

[adulau]

Can you check the size of your database? and review if you have enough free space (as an alter table might create copy of some tables).

 select table_schema, sum((data_length+index_length)/1024/1024) AS MB from information_schema.tables group by 1;

[iglocska]

select table_name, sum((data_length+index_length)/1024/1024) AS MB from information_schema.tables where table_schema = 'misp' group by table_name;

This will show us the size of the tables.

[garrit-schroeder]

MariaDB [misp01]> select table_name, sum((data_length+index_length)/1024/1024) AS MB from information_schema.tables where table_schema = 'misp01' group by table_name;
+-------------------------------+---------------+
| table_name | MB |
+-------------------------------+---------------+
| admin_settings | 0.01562500 |
| attributes | 7109.39062500 |
| attribute_tags | 3065.00000000 |
| bruteforces | 0.01562500 |
| cake_sessions | 0.03125000 |
| correlations | 3279.03125000 |
| events | 10.67187500 |
| event_blacklists | 0.04687500 |
| event_delegations | 0.04687500 |
| event_graph | 0.07812500 |
| event_locks | 0.06250000 |
| event_tags | 2.32812500 |
| favourite_tags | 0.04687500 |
| feeds | 0.03125000 |
| fuzzy_correlate_ssdeep | 0.01562500 |
| galaxies | 0.07812500 |
| galaxy_clusters | 10.89062500 |
| galaxy_elements | 9.90625000 |
| galaxy_reference | 0.07812500 |
| jobs | 17.51562500 |
| logs | 7788.00000000 |
| news | 0.01562500 |
| noticelists | 0.04687500 |
| noticelist_entries | 0.03125000 |
| notification_logs | 0.04687500 |
| objects | 5.73437500 |
| object_references | 13.35937500 |
| object_relationships | 0.06250000 |
| object_templates | 0.15625000 |
| object_template_elements | 0.37500000 |
| organisations | 0.04687500 |
| org_blacklists | 0.01562500 |
| posts | 0.04687500 |
| regexp | 0.01562500 |
| rest_client_histories | 0.06250000 |
| roles | 0.01562500 |
| servers | 0.04687500 |
| shadow_attributes | 0.15625000 |
| shadow_attribute_correlations | 0.12500000 |
| sharing_groups | 0.07812500 |
| sharing_group_orgs | 0.04687500 |
| sharing_group_servers | 0.04687500 |
| sightings | 0.10937500 |
| tags | 0.23437500 |
| tag_collections | 0.06250000 |
| tag_collection_tags | 0.04687500 |
| tasks | 0.01562500 |
| taxonomies | 0.04687500 |
| taxonomy_entries | 0.56250000 |
| taxonomy_predicates | 0.12500000 |
| templates | 0.01562500 |
| template_elements | 0.01562500 |
| template_element_attributes | 0.01562500 |
| template_element_files | 0.01562500 |
| template_element_texts | 0.01562500 |
| template_tags | 0.01562500 |
| threads | 0.07812500 |
| threat_levels | 0.01562500 |
| users | 0.06250000 |
| user_settings | 0.04687500 |
| warninglists | 0.01562500 |
| warninglist_entries | 10.84375000 |
| warninglist_types | 0.01562500 |
| whitelist | 0.01562500 |
+-------------------------------+---------------+
64 rows in set (0,00 sec)

[garrit-schroeder]

MariaDB [misp01]> select table_schema, sum((data_length+index_length)/1024/1024) AS MB from information_schema.tables group by 1;
+--------------------+----------------+
| table_schema | MB |
+--------------------+----------------+
| information_schema | 0.17187500 |
| misp01 | 21326.20312500 |
| misp02 | 23318.90625000 |
| mysql | 1.03130912 |
| performance_schema | 0.00000000 |
+--------------------+----------------+
5 rows in set (0,04 sec)

[garrit-schroeder]

We are running two misp instances with a separate database server. same error occurs on both instances. currently we are trying to fix misp01

[garrit-schroeder]

df -h
/xxxxxxxx xfs 100G 58G 43G 58% /xxxxx ##masked

[iglocska]

Any custom hardening that you guys are doing? If it's not space related it could be file permission related. As a next step if all else fails we can test and try to create it manually.

[garrit-schroeder]

i am not sure how a missing database column can be file permission related.
Could you please explain?
We have set different permissions on our files. mostly read only for apache and on some folders write permissions.

[iglocska]

13579868 SYSTEM SYSTEM 2019-08-21 08:51:39 Server 0 update_database Issues executing the SQL query for 36 The executed SQL query was: ALTER TABLE attribute_tags ADD local tinyint(1) NOT NULL DEFAULT 0;
The returned error is: SQLSTATE[HY000]: General error: 1878 Temporary file write failure

This basically tells us: We tried to add the local flag to the table but it failed. Adding a column means issuing an alter table. Now fun fact about MySQL, alter tables internally actually take the original table, create a temporary copy of it in a separate file, modify the copy, delete the original and move the copy to the original's location.

The reason for the failure is "The returned error is: SQLSTATE[HY000]: General error: 1878 Temporary file write failure" - this means that the temporary file could not be written. This can be due to file permission issues or a lack of space.

[garrit-schroeder]

All right I get it.
But on our Database Server i just checked the file permissions for the data folder of mysql.

pwd
/xxxxx/mysql/data/

347 drwx------ 2 mysql mysql 8192 21. Aug 10:51 misp01

Mysql can write into that folder.
Or do you mean the file permission within the misp directory. In our setup that are different servers.

[iglocska]

It should be able to unless you have some SELinux madness going on. Perhaps the best thing to do is this:

Log into MySQL via the command line using the user used by MISP (mysql -u [misp_mysql_user] -p [misp_db_name]) and then execute the following:

ALTER TABLE `attribute_tags` ADD `local` tinyint(1) NOT NULL DEFAULT 0;

Does this work?

[garrit-schroeder]

MariaDB [misp01]> ALTER TABLE attribute_tags ADD local tinyint(1) NOT NULL DEFAULT 0;
ERROR 1878 (HY000): Temporary file write failure

Same error. I see now

[garrit-schroeder]

What i am wondering too is that this issue only applies to org admins?
Admins can view, edit, populate events with no problem as well Read Only users can see events without a problem.

Next step is for us to expand our file system partition. To at least erase that possibility. Thanks for the support so far guys.
Probably done tomorrow noon.

Cheers.

[iglocska]

Hello there, that makes sense, it's a bit confusing though.

So basically, we consider "community only" to include anyone that has a user on an instance.

This means that if I am part of a community (MISP B), I want to grab the events I can see and take it home to my own instance (MISP A) via a pull. The interaction is initiated by me (org A) on my home instance (MISP A) and the event will be pulled over and downgraded to "organisation only". Organisation only implies that the data is visible by one organisation on the instance, denoted by the local owner organisation (org_id in the event - in this case org A). This is the organisation of whoever creates the data locally, in the case of the pull the admin that initiated the pull (org A) and which has a remote user on the community (MISP B) that has the data in this case.

On the other hand, for pushes it's different. Pushes happen via the sync users of the pushing party (org B), meaning that in the previous scenario, if the community instance (MISP B) that has the data would push the data, they would log into each connected instance (such as MISP A) using their sync user (belonging to org A) and create the data as your organisation only (to org A). This means that you would get data pushed to your instance (MISP B) but you would not be able to see it (as org A) since the data is your org only to the remote instance's organisation (org B).

I know, it sounds confusing, but this is the reason why pushes happen for data that is connected community and higher and pulls can happen for org only data.

Hope this clears it up :)

[iglocska]

BTW, if you are interested in trainings, we offer free training courses in Luxembourg for MISP:

Usage/administration: https://en.xing-events.com/EJKDRZP.html
Hands-on: https://en.xing-events.com/UEXXGRO.html
Developers: https://en.xing-events.com/CQYGYJQ.html

[garrit-schroeder]

Thanks again for the support.
Adding more storage and changing the default MYSQL Temp directory to a location with more drive space did the trick.

Cheers.

[iglocska]

Excellent thanks for the feedback.