hit a wall with remote log monitoring #256

ramd3z · 2021-07-13T01:25:45Z

ramd3z
Jul 13, 2021

Good evening, all. I'm having issues ...

I'm running chiadog on Ubuntu focal with a remote Windows 10 full node.
My chia log setting on the full node is set to info.
I've followed all ssh instructions and can ssh without issue or being asked for a password/passphrase.
I've tried variations of the windows path without success. Currently I'm trying double slashes.
I have an ssh user that is a local admin on my windows 10 machine and I followed the ACL instructions to apply the right permissions to the administrators public key file. Any help would be appreciated.

log_level: DEBUG

chia_logs:
network_log_consumer:
enable: true
remote_file_path: 'C:\Users\phili\.chia\mainnet\log\debug.log'
remote_host: "192.168.1.110"
remote_user: "ssh"
remote_port: 22

Below is my debug output

[2021-07-12 21:11:40] [ INFO] --- Starting Chiadog (v0.6.0) (main.py:54)
[2021-07-12 21:11:40] [ DEBUG] --- starting thread (client mode): 0xef8378b0 (transport.py:1819)
[2021-07-12 21:11:40] [ DEBUG] --- Local version/idstring: SSH-2.0-paramiko_2.7.2 (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Remote version/idstring: SSH-2.0-OpenSSH_for_Windows_8.1 (transport.py:1819)
[2021-07-12 21:11:41] [ INFO] --- Connected (version 2.0, client OpenSSH_for_Windows_8.1) (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- kex algos:['curve25519-sha256', '[email protected]', 'ecdh-sha2-nistp256', 'ecdh-sha2-nistp384', 'ecdh-sha2-nistp521', 'diffie-hellman-group-exchange-sha256', 'diffie-hellman-group16-sha512', 'diffie-hellman-group18-sha512', 'diffie-hellman-group14-sha256', 'diffie-hellman-group14-sha1'] server key:['rsa-sha2-512', 'rsa-sha2-256', 'ssh-rsa', 'ecdsa-sha2-nistp256', 'ssh-ed25519'] client encrypt:['[email protected]', 'aes128-ctr', 'aes192-ctr', 'aes256-ctr', '[email protected]', '[email protected]'] server encrypt:['[email protected]', 'aes128-ctr', 'aes192-ctr', 'aes256-ctr', '[email protected]', '[email protected]'] client mac:['[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', 'hmac-sha2-256', 'hmac-sha2-512', 'hmac-sha1'] server mac:['[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', 'hmac-sha2-256', 'hmac-sha2-512', 'hmac-sha1'] client compress:['none', '[email protected]'] server compress:['none', '[email protected]'] client lang:[''] server lang:[''] kex follows?False (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Kex agreed: [email protected] (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- HostKey agreed: ecdsa-sha2-nistp256 (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Cipher agreed: aes128-ctr (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- MAC agreed: hmac-sha2-256 (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Compression agreed: none (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- kex engine KexCurve25519 specified hash_algo (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Switch to new keys ... (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Trying SSH agent key b'30fa5blahblahblah252d' (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- userauth is OK (transport.py:1819)
[2021-07-12 21:11:41] [ INFO] --- Authentication (publickey) successful! (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 0] Max packet in: 32768 bytes (channel.py:1212)
[2021-07-12 21:11:41] [ DEBUG] --- Received global request "[email protected]" (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Rejecting "[email protected]" global request from server. (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 0] Max packet out: 32768 bytes (channel.py:1212)
[2021-07-12 21:11:41] [ DEBUG] --- Secsh channel 0 opened. (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 0] Sesch channel 0 request ok (channel.py:1212)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 0] EOF received (0) (channel.py:1212)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 0] EOF sent (0) (channel.py:1212)
[2021-07-12 21:11:41] [ INFO] --- Enabled Windows network log consumer. (log_consumer.py:141)
[2021-07-12 21:11:41] [ DEBUG] --- starting thread (client mode): 0xef84e850 (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Local version/idstring: SSH-2.0-paramiko_2.7.2 (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Remote version/idstring: SSH-2.0-OpenSSH_for_Windows_8.1 (transport.py:1819)
[2021-07-12 21:11:41] [ INFO] --- Connected (version 2.0, client OpenSSH_for_Windows_8.1) (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- kex algos:['curve25519-sha256', '[email protected]', 'ecdh-sha2-nistp256', 'ecdh-sha2-nistp384', 'ecdh-sha2-nistp521', 'diffie-hellman-group-exchange-sha256', 'diffie-hellman-group16-sha512', 'diffie-hellman-group18-sha512', 'diffie-hellman-group14-sha256', 'diffie-hellman-group14-sha1'] server key:['rsa-sha2-512', 'rsa-sha2-256', 'ssh-rsa', 'ecdsa-sha2-nistp256', 'ssh-ed25519'] client encrypt:['[email protected]', 'aes128-ctr', 'aes192-ctr', 'aes256-ctr', '[email protected]', '[email protected]'] server encrypt:['[email protected]', 'aes128-ctr', 'aes192-ctr', 'aes256-ctr', '[email protected]', '[email protected]'] client mac:['[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', 'hmac-sha2-256', 'hmac-sha2-512', 'hmac-sha1'] server mac:['[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', '[email protected]', 'hmac-sha2-256', 'hmac-sha2-512', 'hmac-sha1'] client compress:['none', '[email protected]'] server compress:['none', '[email protected]'] client lang:[''] server lang:[''] kex follows?False (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Kex agreed: [email protected] (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- HostKey agreed: ecdsa-sha2-nistp256 (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Cipher agreed: aes128-ctr (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- MAC agreed: hmac-sha2-256 (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Compression agreed: none (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- kex engine KexCurve25519 specified hash_algo (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Switch to new keys ... (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Trying SSH agent key b'30fblahblahblah2d' (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- userauth is OK (transport.py:1819)
[2021-07-12 21:11:41] [ INFO] --- Authentication (publickey) successful! (transport.py:1819)
[2021-07-12 21:11:41] [ INFO] --- Consuming remote log file C:\Users\phili.chia\mainnet\log\debug.log from 192.168.1.110:22 (OS.WINDOWS) (log_consumer.py:108)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 0] Max packet in: 32768 bytes (channel.py:1212)
[2021-07-12 21:11:41] [ INFO] --- Keep-alive check period: 300 seconds (keep_alive_monitor.py:45)
[2021-07-12 21:11:41] [ WARNING] --- Cannot process user events: 0 notifiers are enabled! (notify_manager.py:52)
[2021-07-12 21:11:41] [ INFO] --- Enabled stats for daily notifications (stats_manager.py:37)
[2021-07-12 21:11:41] [ INFO] --- Summary notifications will be sent out every 24 hours starting from 21 o'clock (stats_manager.py:48)
[2021-07-12 21:11:41] [ INFO] --- Enabled parser for harvester activity - eligible plot events. (harvester_activity_parser.py:32)
[2021-07-12 21:11:41] [ INFO] --- Enabled check for farming events. (time_since_last_farm_event.py:22)
[2021-07-12 21:11:41] [ INFO] --- Enabled check for non-decreasing total plot count. (non_decreasing_plots.py:18)
[2021-07-12 21:11:41] [ INFO] --- Enabled check for time taken to respond to challenges. (quick_plot_search_time.py:18)
[2021-07-12 21:11:41] [ INFO] --- Enabled check for found proofs. (found_proofs.py:15)
[2021-07-12 21:11:41] [ INFO] --- Enabled parser for finished signage points. (finished_signage_point_parser.py:28)
[2021-07-12 21:11:41] [ INFO] --- Enabled check for finished signage points. (non_skipped_signage_points.py:19)
[2021-07-12 21:11:41] [ INFO] --- Enabled parser for wallet activity - added coins. (wallet_added_coin_parser.py:26)
[2021-07-12 21:11:41] [ DEBUG] --- Received global request "[email protected]" (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- Rejecting "[email protected]" global request from server. (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 0] Max packet out: 32768 bytes (channel.py:1212)
[2021-07-12 21:11:41] [ DEBUG] --- Secsh channel 0 opened. (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 0] Sesch channel 0 request ok (channel.py:1212)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 1] Max packet in: 32768 bytes (channel.py:1212)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 1] Max packet out: 32768 bytes (channel.py:1212)
[2021-07-12 21:11:41] [ DEBUG] --- Secsh channel 1 opened. (transport.py:1819)
[2021-07-12 21:11:41] [ DEBUG] --- [chan 1] Sesch channel 1 request ok (channel.py:1212)
[2021-07-12 21:11:42] [ DEBUG] --- [chan 1] EOF received (1) (channel.py:1212)
Exception in thread Thread-5:
Traceback (most recent call last):
File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
[2021-07-12 21:11:42] [ DEBUG] --- [chan 1] EOF sent (1) (channel.py:1212)
self.run()
File "/usr/lib/python3.8/threading.py", line 870, in run
self._target(*self._args, **self._kwargs)
File "/home/me/chiadog/src/chia_log/log_consumer.py", line 152, in _consume_loop
if self._has_rotated(self._remote_log_path):
File "/home/me/chiadog/src/chia_log/log_consumer.py", line 172, in _has_rotated
self._log_size = int(stdout.readline())
ValueError: invalid literal for int() with base 10: ''
[2021-07-12 21:11:42] [ DEBUG] --- [chan 0] EOF sent (0) (channel.py:1212)
[2021-07-12 21:16:42] [ DEBUG] --- Keep-alive check for HARVESTER: Last activity 300 seconds ago. (keep_alive_monitor.py:77)

Answered by pieterhelsen

Jul 13, 2021

Looks like it's not an SSH issue, but rather an issue with the log file path.
Could you add the following two lines to src\chia_log\log_consumer.py on line 171:

logging.debug(f"Getting file size for log: {str(path)}")
logging.debug(f"{stdout.readlines()}")

Then run chiadog again and post the chiadog log output for those lines.

View full answer

pieterhelsen · 2021-07-13T09:35:09Z

pieterhelsen
Jul 13, 2021
Collaborator

Looks like it's not an SSH issue, but rather an issue with the log file path.
Could you add the following two lines to src\chia_log\log_consumer.py on line 171:

logging.debug(f"Getting file size for log: {str(path)}")
logging.debug(f"{stdout.readlines()}")

Then run chiadog again and post the chiadog log output for those lines.

4 replies

ramd3z Jul 13, 2021
Author

Thank you

[2021-07-13 07:54:17] [   DEBUG] --- Secsh channel 0 opened. (transport.py:1819)
[2021-07-13 07:54:17] [   DEBUG] --- [chan 0] Sesch channel 0 request ok (channel.py:1212)
[2021-07-13 07:54:17] [   DEBUG] --- [chan 1] Max packet in: 32768 bytes (channel.py:1212)
[2021-07-13 07:54:17] [   DEBUG] --- [chan 1] Max packet out: 32768 bytes (channel.py:1212)
[2021-07-13 07:54:17] [   DEBUG] --- Secsh channel 1 opened. (transport.py:1819)
[2021-07-13 07:54:17] [   DEBUG] --- [chan 1] Sesch channel 1 request ok (channel.py:1212)
[2021-07-13 07:54:17] [   DEBUG] --- Getting file size for log: C:\Users\phili\.chia\mainnet\log\debug.log (log_consumer.py:171)
[2021-07-13 07:54:17] [   DEBUG] --- [chan 1] EOF received (1) (channel.py:1212)
[2021-07-13 07:54:17] [   DEBUG] --- [] (log_consumer.py:172)
Exception in thread Thread-5:
Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
[2021-07-13 07:54:17] [   DEBUG] --- [chan 1] EOF sent (1) (channel.py:1212)
    self.run()
  File "/usr/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/me/chiadog/src/chia_log/log_consumer.py", line 152, in _consume_loop
    if self._has_rotated(self._remote_log_path):
  File "/home/me/chiadog/src/chia_log/log_consumer.py", line 175, in _has_rotated
    self._log_size = int(stdout.readline())
ValueError: invalid literal for int() with base 10: ''
[2021-07-13 07:54:17] [   DEBUG] --- [chan 0] EOF sent (0) (channel.py:1212)

pieterhelsen Jul 13, 2021
Collaborator

Thanks. Could you try running this command from PowerShell and tell us what the output is?

Write-Host((Get-Item C:\Users\phili\.chia\mainnet\log\debug.log).length

Also, can you make sure that the debug.log file is not empty?

pieterhelsen Jul 13, 2021
Collaborator

nevermind; I see what the problem is... It's already fixed in dev, but not pushed to main yet.
You can remove the previously added debug statements and change this line:

chiadog/src/chia_log/log_consumer.py

Line 168 in 429b90c

f"powershell.exe Write-Host((Get-Item {str(path)}).length"

To:

f"powershell.exe Write-Host(Get-Item {str(path)}).length)"

(basically removing the first opening bracket)

This will temporarily solve it until the fix is pushed to main in a new release.

martomi Jul 13, 2021
Maintainer

@pieterhelsen Thanks for investigating this (again), I'll push a release today to finally merge these long-outstanding bug fixes!

ramd3z · 2021-07-13T12:41:22Z

ramd3z
Jul 13, 2021
Author

Ah! I saw that in the issues but assumed it was in already. I’ll edit this evening and run again. Thanks for the help.

…

On Jul 13, 2021, at 8:11 AM, pieterhelsen ***@***.***> wrote: nevermind; I see what the problem is... It's already fixed in dev, but not pushed to main yet. You can remove the previously added debug statements and change this line: https://github.com/martomi/chiadog/blob/429b90cf2d3f74a885d4ffcb748fb63b1521e48b/src/chia_log/log_consumer.py#L168 To: f"powershell.exe Write-Host(Get-Item {str(path)}).length)" (basically removing the first opening bracket) This will temporarily solve it until the fix is pushed to main in a new release. — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or unsubscribe.

2 replies

pieterhelsen Jul 13, 2021
Collaborator

Great! Feel free to mark the solution as an answer once you've verified it solves your issues :)

ramd3z Jul 13, 2021
Author

all is now well. thanks much

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

hit a wall with remote log monitoring #256

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 2 comments 6 replies

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

hit a wall with remote log monitoring #256

ramd3z Jul 13, 2021

Replies: 2 comments · 6 replies

pieterhelsen Jul 13, 2021 Collaborator

ramd3z Jul 13, 2021 Author

pieterhelsen Jul 13, 2021 Collaborator

pieterhelsen Jul 13, 2021 Collaborator

martomi Jul 13, 2021 Maintainer

ramd3z Jul 13, 2021 Author

pieterhelsen Jul 13, 2021 Collaborator

ramd3z Jul 13, 2021 Author

ramd3z
Jul 13, 2021

Replies: 2 comments 6 replies

pieterhelsen
Jul 13, 2021
Collaborator

ramd3z Jul 13, 2021
Author

pieterhelsen Jul 13, 2021
Collaborator

pieterhelsen Jul 13, 2021
Collaborator

martomi Jul 13, 2021
Maintainer

ramd3z
Jul 13, 2021
Author

pieterhelsen Jul 13, 2021
Collaborator

ramd3z Jul 13, 2021
Author