search

atsign-foundation / at_server

The software implementation of Atsign's core technology
https://docs.atsign.com
BSD 3-Clause "New" or "Revised" License
40 stars 12 forks source link

hive error in secondary of kryz_9850 #871

Closed murali-shris closed 2 years ago

murali-shris commented 2 years ago

Describe the bug

To Reproduce

Expected behavior

Screenshots

"INFO|2022-08-18 11:11:52.057468|SecondaryServerBootStrapper|Caught SIGTERM - calling secondaryServerInstance.stop() "
"INFO|2022-08-18 11:11:52.057518|AtSecondaryServer|Executing server stop() "
"INFO|2022-08-18 11:11:52.057529|AtSecondaryServer|Closing ServerSocket "
"INFO|2022-08-18 11:11:52.062946|AtSecondaryServer|Terminating all inbound connections "
"INFO|2022-08-18 11:11:52.068142|AtSecondaryServer|Closing CommitLog HiveBox "
"INFO|2022-08-18 11:11:52.093789|AtSecondaryServer|Closing AccessLog HiveBox "
"INFO|2022-08-18 11:11:52.093857|AtSecondaryServer|Closing NotificationKeyStore HiveBox "
"INFO|2022-08-18 11:11:52.166948|AtSecondaryServer|Closing Main key store HiveBox "
"INFO|2022-08-18 11:11:52.235296|AtSecondaryServer|Stopping scheduled tasks "
"INFO|2022-08-18 11:11:52.235448|SecondaryServerBootStrapper|secondaryServerInstance.stop() completed, and isRunning is false - exiting with status 0 "
"INFO|2022-08-18 11:11:55.419753|AtSecondaryServer|currentAtSign : @kryz_9850 "
"INFO|2022-08-18 11:11:55.767711|HiveBase|commit_log_a5ccd6c390f12f55ce57aa699ee9117ca337d422a81fd9c11a732f8310a3062c initialized successfully "
"INFO|2022-08-18 11:11:56.165293|HiveBase|access_log_a5ccd6c390f12f55ce57aa699ee9117ca337d422a81fd9c11a732f8310a3062c initialized successfully "
"INFO|2022-08-18 11:12:04.447418|HiveBase|notifications_a5ccd6c390f12f55ce57aa699ee9117ca337d422a81fd9c11a732f8310a3062c initialized successfully "
"INFO|2022-08-18 11:13:07.773578|HiveBase|a5ccd6c390f12f55ce57aa699ee9117ca337d422a81fd9c11a732f8310a3062c initialized successfully "
"INFO|2022-08-18 11:13:07.812950|StatsNotificationService|StatsNotificationService is enabled. Runs every 15 seconds "
"INFO|2022-08-18 11:13:07.814557|AtCertificationValidation|Certificates reload job scheduled to run at 2 hours and 14 hours "
"INFO|2022-08-18 11:13:07.862610|AtSecondaryServer|Secondary server started on version : 3.0.21+c3.0.22 on root server : root.atsign.org "
"INFO|2022-08-18 11:13:07.862654|AtSecondaryServer|Secure Socket open for @kryz_9850 ! "
"SEVERE|2022-08-18 11:13:07.911977|SecondaryServerBootStrapper|Uncaught error: HiveError: Cannot read, unknown typeId: 158. Did you forget to register an adapter? "
" Stacktrace: #0      BinaryReaderImpl.read (package:hive/src/binary/binary_reader_impl.dart:325)"
#1      BinaryReaderImpl.readEncrypted (package:hive/src/binary/binary_reader_impl.dart:342)
#2      BinaryReaderImpl.readFrame (package:hive/src/binary/binary_reader_impl.dart:278)
#3      StorageBackendVm.readValue.<anonymous closure> (package:hive/src/backend/vm/storage_backend_vm.dart:111)
<asynchronous suspension>
#4      LazyBoxImpl.get (package:hive/src/box/lazy_box_impl.dart:32)
<asynchronous suspension>
#5      _CustomZone.bindUnaryCallbackGuarded.<anonymous closure> (dart:async/zone.dart:1281)
<asynchronous suspension>
" "
murali-shris commented 2 years ago

Output while opening the hive storage as non-lazy box using standalone dart program

boxName: a5ccd6c390f12f55ce57aa699ee9117ca337d422a81fd9c11a732f8310a3062c
**key:privatekey:signing_keypair_generated
**key:privatekey:at_pkam_publickey
**key:privatekey:at_secret_deleted
**key:cached:public:publickey@colin
**key:cached:public:publickey@visual61
**key:public:_transmitter.wavi@kryz_9850
**key:cached:@kryz_9850:shared_key@ai6bh
**key:public:ttl:-1:ttr:-1:datasignature:h35rdygk+-fnvraeptv5uq7mtu/ct+-a8mexoku0rsqslvbpqbccez29xbkqqm1pg03ptj373q3duwbqlcqeruf64rwaqylexadjmcmlyswswjc09h2g2kbvniss/tpqdln31xdzkyxhbfeh2gse2q1xgnxmwt0doe
Unhandled exception:
HiveError: Cannot read, unknown typeId: 158. Did you forget to register an adapter?
#0      BinaryReaderImpl.read (package:hive/src/binary/binary_reader_impl.dart:324:11)
#1      BinaryReaderImpl.readEncrypted (package:hive/src/binary/binary_reader_impl.dart:341:24)
#2      BinaryReaderImpl.readFrame (package:hive/src/binary/binary_reader_impl.dart:277:26)
#3      FrameHelper.framesFromBytes (package:hive/src/binary/frame_helper.dart:21:26)
#4      FrameIoHelper.framesFromFile (package:hive/src/io/frame_io_helper.dart:42:12)
<asynchronous suspension>
#5      StorageBackendVm.initialize (package:hive/src/backend/vm/storage_backend_vm.dart:86:11)
<asynchronous suspension>
murali-shris commented 2 years ago

commit entry corresponding to the malformed key CommitEntry{AtKey: public:ttl:-1:ttr:-1:datasignature:h35rdygk+fnvraeptv5uq7mtu/ct+a8mexoku0rsqslvbpqbccez29xbkqqm1pg03ptj373q3duwbqlcqeruf64rwaqylexadjmcmlyswswjc09h2g2kbvniss/tpqdln31xdzkyxhbfeh2gse2q1xgnxmwt0doezyus/eo9t0krj+ftewobybhygoqc+zfwan/3+6pzt4j5+ft2epznkic5jwv/gkb8wybvpjkxswmrvsla3+m2b36/k2sofk/g9w/m1f6t3pr1qjcyabv3sgcctbwqjm6nvd2f5lbde90+eukufuubd5ldfou+jehopbyhi3o6qvu8uvp1liwjua==:isbinary:false:isencrypted:false:public:kryz.kryz_9850@kryz_9850, operation: CommitOp.UPDATE_ALL, commitId:235166, opTime: 2022-07-20 19:10:34.685Z, internal_seq: 235166}

murali-shris commented 2 years ago

Update command regex doesn't work as expected when ttl/ttb value is negative. Fixed the regex and later on any negative values passed will be rejected by server validation. @kalluriramkumar will fix the validation in at_client

sitaram-kalluri commented 2 years ago

Update command regex doesn't work as expected when ttl/ttb value is negative. Fixed the regex and later on any negative values passed will be rejected by server validation. @kalluriramkumar will fix the validation in at_client

Implemented the validation of metadata for the put request. Following the PR: https://github.com/atsign-foundation/at_client_sdk/pull/664

murali-shris commented 2 years ago

Exception not encountered in the secondary for the past 10 days.. murali@canary-01:~$ sudo docker service logs --since '2022-08-20T00:00:00' -f 8j7h6oluln3n|grep 'SEVERE' d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.j0l950zcg60b@canary-02.us-central1-b.c.secondaries.internal | SEVERE|2022-08-24 03:36:04.348105|InboundListener|SocketException: Connection reset by peer (OS Error: Connection reset by peer, errno = 104), address = 0.0.0.0, port = 7246 d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.j0l950zcg60b@canary-02.us-central1-b.c.secondaries.internal | SEVERE|2022-08-24 03:36:04.348332|InboundListener|SocketException: Connection reset by peer (OS Error: Connection reset by peer, errno = 104), address = 0.0.0.0, port = 7246 d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.j0l950zcg60b@canary-02.us-central1-b.c.secondaries.internal | SEVERE|2022-08-24 11:44:08.874397|DefaultResponseHandler|exception in writing response to socket:Exception: Connection is invalid d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.j0l950zcg60b@canary-02.us-central1-b.c.secondaries.internal | SEVERE|2022-08-24 11:44:08.875473|GlobalExceptionHandler|Exception: Connection is invalid d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.7a1klbj7e56d@canary-03.us-central1-c.c.secondaries.internal | SEVERE|2022-09-01 00:00:10.396516|DefaultVerbExecutor|No handler found for command:
d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.7a1klbj7e56d@canary-03.us-central1-c.c.secondaries.internal | SEVERE|2022-09-01 00:00:10.396698|AtSecondaryServer|Exception occurred in executing the verb: Exception: invalid command d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.7nhaacl1n44r@canary-03.us-central1-c.c.secondaries.internal | SEVERE|2022-09-02 05:46:36.874783|InboundListener|SocketException: Connection reset by peer (OS Error: Connection reset by peer, errno = 104), address = 0.0.0.0, port = 7246 d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.7nhaacl1n44r@canary-03.us-central1-c.c.secondaries.internal | SEVERE|2022-09-02 05:46:36.875120|InboundListener|SocketException: Connection reset by peer (OS Error: Connection reset by peer, errno = 104), address = 0.0.0.0, port = 7246 d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.7a1klbj7e56d@canary-03.us-central1-c.c.secondaries.internal | SEVERE|2022-09-01 01:45:09.889664|DefaultVerbExecutor|exception in processing command :from:@kryz_9850 d8f88b04-3047-5ec3-ba81-3c65f62764dd_secondary.1.7a1klbj7e56d@canary-03.us-central1-c.c.secondaries.internal | SEVERE|2022-09-01 01:45:09.889704|AtSecondaryServer|Exception occurred in executing the verb: from:@kryz_9850