search

metwork-framework / mfdata

metwork/mfdata module
http://metwork-framework.org/
BSD 3-Clause "New" or "Revised" License
6 stars 4 forks source link

guess_file_type interfering with httpsend behavior #419

Closed ghost closed 2 years ago

ghost commented 2 years ago

Hi,

My plugin seems to work flawlessly

2021-12-17T12:30:14.692316Z     [INFO] (directory_observer#71865) /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT added to redis queue step.apicvf_httpsend_cdp.main

==> redis.log <==
68321:M 17 Dec 2021 12:30:14.694 * 1 changes in 60 seconds. Saving...
68321:M 17 Dec 2021 12:30:14.694 * Background saving started by pid 73506

==> step_apicvf_httpsend_cdp_main.log <==
2021-12-17T12:30:14.693039Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Start the processing of /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT...
2021-12-17T12:30:14.693614Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Move /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT to /home/mfdata/var/in/tmp/apicvf_httpsend_cdp.main/961b4a88d8924005a9d50104dc51be18 (to process it)
2021-12-17T12:30:14.693924Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Setting tag first.core.original_uid = 961b4a88d8924005a9d50104dc51be18
2021-12-17T12:30:14.694079Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Setting tag first.core.original_basename = FPFR42_ATOS_171230.20211217123000_1234567_F.LT
2021-12-17T12:30:14.695516Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Setting tag first.core.original_dirname = incoming
2021-12-17T12:30:14.695805Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) invoking POST on http://localhost:18868/procedere/cdp ...

The POST went fine. Now, installing guess_file_type :

plugins.install /opt/metwork-mfdata/share/plugins/guess_file_type-1.2.0-1.metwork.mfdata.plugin 
- Checking plugin file...                                  [ OK ]              
- Installing plugin guess_file_type...                     [ OK ]
┌Installed plugins (3)┬──────────┬──────────┬──────────────────────────────────────────────┐
│ Name                │ Version  │ Release  │ Home                                         │
├─────────────────────┼──────────┼──────────┼──────────────────────────────────────────────┤
│ apicvf_httpsend_cdp │ dev_link │ dev_link │ /home/mfdata/var/plugins/apicvf_httpsend_cdp │
│ switch              │ 1.2.0    │ 1        │ /home/mfdata/var/plugins/switch              │
│ guess_file_type     │ 1.2.0    │ 1        │ /home/mfdata/var/plugins/guess_file_type     │
└─────────────────────┴──────────┴──────────┴──────────────────────────────────────────────┘
2021-12-17T12:32:34.946420Z     [INFO] (directory_observer#73931) /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT added to redis queue step.apicvf_httpsend_cdp.main

==> step_apicvf_httpsend_cdp_main.log <==
2021-12-17T12:32:34.945944Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Start the processing of /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT...
2021-12-17T12:32:34.946875Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Move /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT to /home/mfdata/var/in/tmp/apicvf_httpsend_cdp.main/ef5cae70634544a28c57fe579449e740 (to process it)
2021-12-17T12:32:34.947061Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Setting tag first.core.original_uid = ef5cae70634544a28c57fe579449e740
2021-12-17T12:32:34.947270Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Setting tag first.core.original_basename = FPFR42_ATOS_171230.20211217123000_1234567_F.LT
2021-12-17T12:32:34.947491Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) Setting tag first.core.original_dirname = incoming
2021-12-17T12:32:34.947651Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) invoking POST on http://localhost:18868/procedere/cdp ...
2021-12-17T12:32:35.220219Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) ok (status_code=200)
2021-12-17T12:32:35.221003Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#71142) End of the /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT processing after 274 ms

My plugin is still working, but guess_file_type is not doing anything So : mfdata.stop && mfdata.start

2021-12-17T12:34:40.869800Z     [INFO] (mfdata.guess_file_type.main#74809) Start the processing of /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT...
2021-12-17T12:34:40.870614Z     [INFO] (mfdata.guess_file_type.main#74809) Move /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT to /home/mfdata/var/in/tmp/guess_file_type.main/5857ca3c3dc1473380593f76ca7c40d1 (to process it)
2021-12-17T12:34:40.870830Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag first.core.original_uid = 5857ca3c3dc1473380593f76ca7c40d1
2021-12-17T12:34:40.870992Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag first.core.original_basename = FPFR42_ATOS_171230.20211217123000_1234567_F.LT
2021-12-17T12:34:40.871253Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag first.core.original_dirname = incoming
2021-12-17T12:34:40.871375Z     [INFO] (mfdata.guess_file_type.main#74809) Processing file: /home/mfdata/var/in/tmp/guess_file_type.main/5857ca3c3dc1473380593f76ca7c40d1
2021-12-17T12:34:40.871488Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag 0.guess_file_type.main.ascii_header = cdp_injected;random;202112171230;100;002047;-191659;-183
2021-12-17T12:34:40.871547Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag latest.guess_file_type.main.ascii_header = cdp_injected;random;202112171230;100;002047;-191659;-183
2021-12-17T12:34:40.875230Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag 0.guess_file_type.main.system_magic = ASCII text
2021-12-17T12:34:40.875389Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag latest.guess_file_type.main.system_magic = ASCII text
2021-12-17T12:34:40.875487Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag 0.guess_file_type.main.size = 879
2021-12-17T12:34:40.875544Z     [INFO] (mfdata.guess_file_type.main#74809) Setting tag latest.guess_file_type.main.size = 879
2021-12-17T12:34:40.876307Z     [INFO] (mfdata.guess_file_type.main#74809) File /home/mfdata/var/in/tmp/guess_file_type.main/5857ca3c3dc1473380593f76ca7c40d1 moved to /home/mfdata/var/in/step.switch.main/5857ca3c3dc1473380593f76ca7c40d1
2021-12-17T12:34:40.877226Z     [INFO] (mfdata.guess_file_type.main#74809) End of the /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT processing after 7 ms

==> directory_observer.log <==
2021-12-17T12:34:40.869087Z     [INFO] (directory_observer#74838) /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT added to redis queue step.guess_file_type.main
2021-12-17T12:34:40.876877Z     [INFO] (directory_observer#74838) /home/mfdata/var/in/step.switch.main/5857ca3c3dc1473380593f76ca7c40d1 added to redis queue step.switch.main

==> step_switch_main.log <==
2021-12-17T12:34:40.878001Z     [INFO] (mfdata.switch.main#74804) Start the processing of /home/mfdata/var/in/step.switch.main/5857ca3c3dc1473380593f76ca7c40d1...
2021-12-17T12:34:40.879161Z     [INFO] (mfdata.switch.main#74804) Move /home/mfdata/var/in/step.switch.main/5857ca3c3dc1473380593f76ca7c40d1 to /home/mfdata/var/in/tmp/switch.main/5857ca3c3dc1473380593f76ca7c40d1 (to process it)
2021-12-17T12:34:40.881595Z     [INFO] (mfdata.switch.main#74804) Processing file: /home/mfdata/var/in/tmp/switch.main/5857ca3c3dc1473380593f76ca7c40d1
2021-12-17T12:34:40.881754Z     [INFO] (mfdata.switch.main#74804) 1 actions matched for file=/home/mfdata/var/in/tmp/switch.main/5857ca3c3dc1473380593f76ca7c40d1
2021-12-17T12:34:40.884773Z     [INFO] (mfdata.switch.main#74804) File /home/mfdata/var/in/tmp/switch.main/5857ca3c3dc1473380593f76ca7c40d1 moved to /home/mfdata/var/in/step.apicvf_httpsend_cdp.main/5857ca3c3dc1473380593f76ca7c40d1
2021-12-17T12:34:40.885353Z     [INFO] (mfdata.switch.main#74804) End of the /home/mfdata/var/in/step.switch.main/5857ca3c3dc1473380593f76ca7c40d1 processing after 7 ms

Now, guess_file_type is acting on the file. And my plugin seems to handle the file, but does nothing (no POST)

plugins.uninstall guess_file_type
- Uninstalling plugin guess_file_type...                   [ OK ]
==> step_apicvf_httpsend_cdp_main.log <==
2021-12-17T12:36:56.876190Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) ok (status_code=200)
2021-12-17T12:36:56.876843Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) End of the /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT processing after 308 ms
2021-12-17T12:37:09.180708Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) Start the processing of /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT...
2021-12-17T12:37:09.181553Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) Move /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT to /home/mfdata/var/in/tmp/apicvf_httpsend_cdp.main/01476ff9ca4747e4856d2109509f121e (to process it)
2021-12-17T12:37:09.181787Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) Setting tag first.core.original_uid = 01476ff9ca4747e4856d2109509f121e
2021-12-17T12:37:09.181965Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) Setting tag first.core.original_basename = FPFR42_ATOS_171230.20211217123000_1234567_F.LT
2021-12-17T12:37:09.182295Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) Setting tag first.core.original_dirname = incoming
2021-12-17T12:37:09.182488Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) invoking POST on http://localhost:18868/procedere/cdp ...

==> directory_observer.log <==
2021-12-17T12:37:09.181217Z     [INFO] (directory_observer#76491) /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT added to redis queue step.apicvf_httpsend_cdp.main

==> step_apicvf_httpsend_cdp_main.log <==
2021-12-17T12:37:09.449273Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) ok (status_code=200)
2021-12-17T12:37:09.450006Z     [INFO] (mfdata.apicvf_httpsend_cdp.main#74795) End of the /home/mfdata/var/in/incoming/FPFR42_ATOS_171230.20211217123000_1234567_F.LT processing after 269 ms

POST is back.

ghost commented 2 years ago

The problem seems to be in mfdata.stop && mfdata.start The configs are not loaded in some cases (module and/or plugin configs). Installing guess_file_type may trigger it ? This issue is not correct, need to investigate more on the config loading problem, closing.