Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

non-nrtm data source gets loaded, then deleted #186

Closed
troy2914 opened this issue Jan 31, 2019 · 3 comments
Closed

non-nrtm data source gets loaded, then deleted #186

troy2914 opened this issue Jan 31, 2019 · 3 comments
Labels
bug Something isn't working release blocker blocks the next release

Comments

@troy2914
Copy link
Member

data get loaded:
2019-01-31 18:54:18,858 irrd[27482]: [irrd.mirroring.parsers#INFO] File import for REGISTROBR: 15453 objects read, 15453 objects inserted, ignored 0 due to errors, ignored 0 due to object_class_filter, serial 194, source /home/irrd/dbs/registrobr.db
2019-01-31 18:55:39,879 irrd[27482]: [irrd.mirroring.parsers#INFO] File import for RPKI: 73346 objects read, 73346 objects inserted, ignored 0 due to errors, ignored 0 due to object_class_filter, serial 191, source /home/irrd/dbs/rpki.db
2019-01-31 18:55:50,899 irrd[27482]: [irrd.mirroring.parsers#INFO] File import for ARIN-WHOIS: 96599 objects read, 96599 objects inserted, ignored 0 due to errors, ignored 0 due to object_class_filter, serial 447, source /home/irrd/dbs/arin-whois.db

source is checked for updates:
2019-01-31 18:58:51,993 irrd[27482]: [irrd.mirroring.mirror_runners_import#INFO] Running full import of REGISTROBR from ['file:///home/irrd/dbs/registrobr.db'], serial from file:///home/irrd/dbs/REGISTROBR.CURRENTSERIAL
2019-01-31 18:58:51,993 irrd[27482]: [irrd.mirroring.mirror_runners_import#INFO] Current newest serial seen for REGISTROBR is 194, import_serial is 194, cancelling import.
2019-01-31 18:58:52,932 irrd[27482]: [irrd.mirroring.mirror_runners_import#INFO] Running full import of RPKI from ['file:///home/irrd/dbs/rpki.db'], serial from file:///home/irrd/dbs/RPKI.CURRENTSERIAL
2019-01-31 18:58:52,933 irrd[27482]: [irrd.mirroring.mirror_runners_import#INFO] Current newest serial seen for RPKI is 191, import_serial is 191, cancelling import.
2019-01-31 18:58:53,098 irrd[27482]: [irrd.mirroring.mirror_runners_import#INFO] Running full import of ARIN-WHOIS from ['file:///home/irrd/dbs/arin-whois.db'], serial from file:///home/irrd/dbs/ARIN-WHOIS.CURRENTSERIAL
2019-01-31 18:58:53,098 irrd[27482]: [irrd.mirroring.mirror_runners_import#INFO] Current newest serial seen for ARIN-WHOIS is 447, import_serial is 447, cancelling import.

database log shows:
2019-01-31 18:58:51.720 UTC [27707] irrd@irrd LOG: duration: 0.032 ms statement: BEGIN
2019-01-31 18:58:51.720 UTC [27707] irrd@irrd LOG: duration: 0.252 ms statement: SELECT database_status.pk, database_status.source, database_status.serial_oldest_seen, database_status.serial_newest_seen, database_status.serial_oldest_journal, database_status.serial_newest_journal, database_status.serial_last_export, database_status.force_reload, database_status.last_error, database_status.last_error_timestamp, database_status.created, database_status.updated
FROM database_status
WHERE database_status.source IN ('ARIN-WHOIS') ORDER BY CASE WHEN (database_status.source = 'ARIN-WHOIS') THEN 1 ELSE 100000 END, database_status.source ASC
2019-01-31 18:58:51.722 UTC [27507] irrd@irrd LOG: duration: 0.039 ms statement: BEGIN
2019-01-31 18:58:51.722 UTC [27507] irrd@irrd LOG: duration: 0.276 ms statement: SELECT database_status.pk, database_status.source, database_status.serial_oldest_seen, database_status.serial_newest_seen, database_status.serial_oldest_journal, database_status.serial_newest_journal, database_status.serial_last_export, database_status.force_reload, database_status.last_error, database_status.last_error_timestamp, database_status.created, database_status.updated
FROM database_status
WHERE database_status.source IN ('RPKI') ORDER BY CASE WHEN (database_status.source = 'RPKI') THEN 1 ELSE 100000 END, database_status.source ASC
2019-01-31 18:58:51.726 UTC [27509] irrd@irrd LOG: duration: 0.020 ms statement: BEGIN
2019-01-31 18:58:51.726 UTC [27509] irrd@irrd LOG: duration: 0.206 ms statement: SELECT database_status.pk, database_status.source, database_status.serial_oldest_seen, database_status.serial_newest_seen, database_status.serial_oldest_journal, database_status.serial_newest_journal, database_status.serial_last_export, database_status.force_reload, database_status.last_error, database_status.last_error_timestamp, database_status.created, database_status.updated
FROM database_status
WHERE database_status.source IN ('REGISTROBR') ORDER BY CASE WHEN (database_status.source = 'REGISTROBR') THEN 1 ELSE 100000 END, database_status.source ASC
2019-01-31 18:58:51.787 UTC [27701] irrd@irrd LOG: duration: 0.046 ms statement: COMMIT
2019-01-31 18:58:51.796 UTC [27703] irrd@irrd LOG: duration: 0.041 ms statement: COMMIT
2019-01-31 18:58:51.797 UTC [27515] irrd@irrd LOG: duration: 0.113 ms statement: COMMIT
2019-01-31 18:58:51.806 UTC [27699] irrd@irrd LOG: duration: 0.023 ms statement: COMMIT
2019-01-31 18:58:51.991 UTC [27509] irrd@irrd LOG: duration: 262.900 ms statement: DELETE FROM rpsl_objects WHERE rpsl_objects.source = 'REGISTROBR'
2019-01-31 18:58:51.993 UTC [27509] irrd@irrd LOG: duration: 0.229 ms statement: DELETE FROM rpsl_database_journal WHERE rpsl_database_journal.source = 'REGISTROBR'
2019-01-31 18:58:52.012 UTC [27518] irrd@irrd LOG: duration: 0.046 ms statement: COMMIT
2019-01-31 18:58:52.041 UTC [27513] irrd@irrd LOG: duration: 0.077 ms statement: COMMIT
2019-01-31 18:58:52.113 UTC [27509] irrd@irrd LOG: duration: 119.393 ms statement: COMMIT
2019-01-31 18:58:52.136 UTC [27505] irrd@irrd LOG: duration: 0.060 ms statement: COMMIT
2019-01-31 18:58:52.310 UTC [27705] irrd@irrd LOG: duration: 0.046 ms statement: COMMIT
2019-01-31 18:58:52.931 UTC [27507] irrd@irrd LOG: duration: 1203.960 ms statement: DELETE FROM rpsl_objects WHERE rpsl_objects.source = 'RPKI'
2019-01-31 18:58:52.932 UTC [27507] irrd@irrd LOG: duration: 0.234 ms statement: DELETE FROM rpsl_database_journal WHERE rpsl_database_journal.source = 'RPKI'
2019-01-31 18:58:53.050 UTC [27507] irrd@irrd LOG: duration: 116.939 ms statement: COMMIT
2019-01-31 18:58:53.097 UTC [27707] irrd@irrd LOG: duration: 1373.529 ms statement: DELETE FROM rpsl_objects WHERE rpsl_objects.source = 'ARIN-WHOIS'
2019-01-31 18:58:53.098 UTC [27707] irrd@irrd LOG: duration: 0.247 ms statement: DELETE FROM rpsl_database_journal WHERE rpsl_database_journal.source = 'ARIN-WHOIS'
2019-01-31 18:58:53.281 UTC [27707] irrd@irrd LOG: duration: 182.167 ms statement: COMMIT

if we are going to cancel the import, we should not delete the source.

And what's worse is the database_status was not updated. so any further checking of updates to the source, say the serial number is current.

Also may be related, it appears the irrd_database_update also deleted records for those 3 sources.

@troy2914 troy2914 added bug Something isn't working release blocker blocks the next release labels Jan 31, 2019
@troy2914
Copy link
Member Author

oops, forgot to mention this was running version 135a39b

@mxsasha mxsasha closed this as completed in cc0b8ea Feb 1, 2019
@mxsasha
Copy link
Collaborator

mxsasha commented Feb 1, 2019

Are you entirely sure irrd_database_update deleted records too? Because I'm not aware of any way in which it could, so it seems very coincidental that a bug like that would pop up exactly at the same time as another bug (for which code had changed), and affect exactly the same data.

@troy2914
Copy link
Member Author

troy2914 commented Feb 2, 2019

No I am not sure, in fact seems to related what you fixed. Leaving this as closed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working release blocker blocks the next release
Projects
None yet
Development

No branches or pull requests

2 participants