search

ipsingh06 / seedsync

Sync your seedbox. Fast. And more.
https://ipsingh06.github.io/seedsync/
Apache License 2.0
308 stars 43 forks source link

Error parsing lftp job status #55

Closed markhalliwell closed 4 years ago

markhalliwell commented 4 years ago 
2020/06/08 24:41:05 - DEBUG - RemoteScanner - Running a scan
2020/06/08 24:41:05 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'tv'
2020/06/08 24:41:05 - DEBUG - RemoteScanner.RemoteScanner.Sshcp - Command: ssh (redacted)
2020/06/08 24:41:06 - DEBUG - LocalScanner - Running a scan
2020/06/08 24:41:06 - DEBUG - LocalScanner - Scan took 0.056s
2020/06/08 24:41:06 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'tv'
2020/06/08 24:41:07 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'tv'
2020/06/08 24:41:08 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'tv'
2020/06/08 24:41:08 - DEBUG - RemoteScanner.RemoteScanner.Sshcp - Return code: 0
2020/06/08 24:41:08 - DEBUG - RemoteScanner.RemoteScanner.Sshcp - Command took 2.365s
2020/06/08 24:41:08 - DEBUG - RemoteScanner - Scan took 2.366s
2020/06/08 24:41:08 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'tv'
2020/06/08 24:41:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'tv'
2020/06/08 24:41:10 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - LftpJobStateParser error: Missing queue header line 1: 2020-06-08 05:41:10 sftp://(redacted).mkv -> /downloads/tv/(redacted).mkv.lftp 0-100812963 284.0 KiB/s
2020/06/08 24:41:10 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - Status: 2020-06-08 05:41:10 sftp://(redacted).mkv -> /downloads/tv/(redacted).mkv.lftp 0-100812963 284.0 KiB/s [0] queue (sftp://(redacted)) -- 17.77 MiB/s sftp://(redacted) Now executing: [1] mirror -c /home/user/media/tv /downloads/ -- 30G/30G (97%) 17.77 MiB/s [1] mirror -c /home/user/media/tv /downloads/ -- 30G/30G (97%) 17.77 MiB/s \mirror `(redacted)' -- 19G/20G (96%) 17.77 MiB/s \mirror `(redacted)' \transfer `(redacted).mkv' `(redacted).mkv', got 1785656160 of 1790938502 (99%) 249.6K/s eta:20s \chunk 0-71637542 `(redacted).mkv' at 66355200 (3%) 249.6K/s eta:20s [Receiving data] \transfer `(redacted).mkv' `(redacted).mkv', got 1290108928 of 2057345443 (62%) 17.52M/s eta:3m \chunk 0-82293835 `(redacted).mkv' at 39157760 (1%) 537.3K/s eta:79s [Receiving data] \chunk 1975051626-2057345442 `(redacted).mkv' at 2050680170 (91%) 992.7K/s eta:6s [Receiving data] \chunk 1892757809-1975051625 `(redacted).mkv' at 1916580145 (28%) 398.3K/s eta:3m [Receiving data] \chunk 1810463992-1892757808 `(redacted).mkv' at 1870724344 (73%) 952.9K/s eta:26s [Receiving data] \chunk 1728170175-1810463991 `(redacted).mkv' at 1781450943 (64%) 698.8K/s eta:39s [Receiving data] \chunk 1645876358-1728170174 `(redacted).mkv' at 1700861062 (66%) 629.6K/s eta:35s [Receiving data] \chunk 1563582541-1645876357 `(redacted).mkv' at 1591435341 (33%) 367.3K/s eta:2m [Receiving data] \chunk 1481288724-1563582540 `(redacted).mkv' at 1542106132 (73%) 798.3K/s eta:25s [Receiving data] \chunk 1398994907-1481288723 `(redacted).mkv' at 1447720923 (59%) 631.1K/s eta:49s [Receiving data] \chunk 1316701090-1398994906 `(redacted).mkv' at 1364181922 (57%) 594.5K/s eta:52s [Receiving data] \chunk 1234407273-1316701089 `(redacted).mkv' at 1284083561 (60%) 646.4K/s eta:47s [Receiving data] \chunk 1152113456-1234407272 `(redacted).mkv' at 1190419248 (46%) 666.6K/s eta:82s [Receiving data] \chunk 1069819639-1152113455 `(redacted).mkv' at 1128179447 (70%) 700.5K/s eta:29s [Receiving data] \chunk 987525822-1069819638 `(redacted).mkv' at 1033401022 (55%) 560.4K/s eta:56s [Receiving data] \chunk 905232005-987525821 `(redacted).mkv' at 949239429 (53%) 779.0K/s eta:62s [Receiving data] \chunk 822938188-905232004 `(redacted).mkv' at 853838412 (37%) 578.5K/s eta:2m [Receiving data] \chunk 740644371-822938187 `(redacted).mkv' at 781735443 (49%) 558.3K/s eta:71s [Receiving data] \chunk 658350554-740644370 `(redacted).mkv' at 734077402 (92%) 1.06M/s eta:6s [Receiving data] \chunk 576056737-658350553 `(redacted).mkv' at 640445857 (78%) 923.6K/s eta:20s [Receiving data] \chunk 493762920-576056736 `(redacted).mkv' at 547305832 (65%) 731.4K/s eta:38s [Receiving data] \chunk 411469103-493762919 `(redacted).mkv' at 466158895 (66%) 686.8K/s eta:36s [Receiving data] \chunk 329175286-411469102 `(redacted).mkv' at 394809590 (79%) 955.9K/s eta:18s [Receiving data] \chunk 246881469-329175285 `(redacted).mkv' at 312646845 (79%) 1.05M/s eta:18s [Receiving data] \chunk 164587652-246881468 `(redacted).mkv' at 204728452 (48%) 558.6K/s eta:75s [Receiving data] \chunk 82293835-164587651 `(redacted).mkv' at 152286283 (85%) 840.1K/s eta:12s [Receiving data]
2020/06/08 24:41:10 - ERROR - seedsync.ControllerJob - Caught exception in job ControllerJob
Traceback (most recent call last):
File "/app/python/lftp/job_status_parser.py", line 81, in parse
statuses += self.__parse_queue(lines)
File "/app/python/lftp/job_status_parser.py", line 486, in __parse_queue
raise ValueError("Missing queue header line 1: {}".format(line))
ValueError: Missing queue header line 1: 2020-06-08 05:41:10 sftp://(redacted).mkv -> /downloads/tv/(redacted).mkv.lftp 0-100812963 284.0 KiB/s

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/app/python/common/job.py", line 44, in run
self.execute()
File "/app/python/controller/controller_job.py", line 29, in execute
self.__controller.process()
File "/app/python/controller/controller.py", line 202, in process
self.__update_model()
File "/app/python/controller/controller.py", line 295, in __update_model
lftp_statuses = self.__lftp.status()
File "/app/python/lftp/lftp.py", line 314, in status
statuses = self.__job_status_parser.parse(statuses_str)
File "/app/python/lftp/job_status_parser.py", line 86, in parse
raise LftpJobStatusParserError("Error parsing lftp job status")
lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status
2020/06/08 24:41:10 - DEBUG - seedsync.ControllerJob - Calling cleanup for ControllerJob
2020/06/08 24:41:10 - DEBUG - seedsync.Controller - Exiting controller
2020/06/08 24:41:10 - ERROR - seedsync - Caught exception
Traceback (most recent call last):
File "/app/python/lftp/job_status_parser.py", line 81, in parse
statuses += self.__parse_queue(lines)
File "/app/python/lftp/job_status_parser.py", line 486, in __parse_queue
raise ValueError("Missing queue header line 1: {}".format(line))
ValueError: Missing queue header line 1: 2020-06-08 05:41:10 sftp://(redacted).mkv -> /downloads/tv/(redacted).mkv.lftp 0-100812963 284.0 KiB/s

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/app/python/seedsync.py", line 162, in run
controller_job.propagate_exception()
File "/app/python/common/job.py", line 77, in propagate_exception
raise exc_info[1].with_traceback(exc_info[2])
File "/app/python/common/job.py", line 44, in run
self.execute()
File "/app/python/controller/controller_job.py", line 29, in execute
self.__controller.process()
File "/app/python/controller/controller.py", line 202, in process
self.__update_model()
File "/app/python/controller/controller.py", line 295, in __update_model
lftp_statuses = self.__lftp.status()
File "/app/python/lftp/lftp.py", line 314, in status
statuses = self.__job_status_parser.parse(statuses_str)
File "/app/python/lftp/job_status_parser.py", line 86, in parse
raise LftpJobStatusParserError("Error parsing lftp job status")
lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status
2020/06/08 24:41:11 - DEBUG - ActiveScanner - Process received terminate flag
2020/06/08 24:41:11 - DEBUG - ActiveScanner - Exiting process
2020/06/08 24:41:14 - DEBUG - ExtractProcess - Process received terminate flag
2020/06/08 24:41:15 - DEBUG - seedsync.Controller.MPLogger - Stopped listener thread
2020/06/08 24:41:15 - INFO - seedsync.Controller - Exited controller

Likely related to #35

ipsingh06 commented 4 years ago

Mark, is this on the latest version? This error was fixed in version 0.7.1. If you still see it, please enable Debug Logs in Settings, and send me the logs including the crash.

markhalliwell commented 4 years ago

Yes, I'm running v0.7.3. I currently have this disabled due to some local issues I'm working through (transferring files, don't need this to mess it up). I'll try to get the debug log when I can. For now, the output I already provided above is all I got.

markhalliwell commented 4 years ago

I've updated the output above to include the debug about before and after the error.

TheFeelTrain commented 4 years ago

I have the same problem, but it did not start until I updated to 0.7.3. I was previously on 0.7.0 before that so whatever causes Error parsing lftp job status must have been in-between those.

Right now I have to manually use the Restart multiple times a day to get it working again.

TheFeelTrain commented 4 years ago

Here is my log (with identifying info removed). Looks exactly the same as Mark's.

2020/06/08 12:31:36 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - LftpJobStateParser error: Missing queue header line 1: 2020-06-08 19:31:36 sftp://username@domain.com/path/video.mkv -> /path/video.mkv.lftp 708761702-945015599 1.87 MiB/s
2020/06/08 12:31:36 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - Status: 2020-06-08 19:31:36 sftp://username@domain.com/path/video.mkv -> /path/video.mkv.lftp 708761702-945015599 1.87 MiB/s [0] queue (sftp://username:password@domain.com) -- 15.23 MiB/s sftp://username:password@domain.com/path Now executing: [1] mirror -c /path/tv /downloads/ -- 99G/117G (84%) 15.23 MiB/s [1] mirror -c /path/tv /downloads/ -- 99G/117G (84%) 15.23 MiB/s \mirror `directory1' \mirror `directory1/directory2' -- 32G/51G (62%) 15.23 MiB/s \transfer `directory1/directory2/video.mkv' `video.mkv', got 2773401069 of 2835046775 (97%) 15.23M/s eta:13s \chunk 0-236253908 `video.mkv' at 235143168 (8%) 2.01M/s eta:1s [Receiving data] \chunk 2362538981-2598792877 `video.mkv' at 2595814373 (98%) 2.00M/s eta:2s [Receiving data] \chunk 1890031187-2126285083 `video.mkv' at 2114000467 (94%) 1.69M/s eta:7s [Receiving data] \chunk 1653777290-1890031186 `video.mkv' at 1879352202 (95%) 1.87M/s eta:6s [Receiving data] \chunk 1181269496-1417523392 `video.mkv' at 1410776568 (97%) 1.80M/s eta:4s [Receiving data] \chunk 708761702-945015598 `video.mkv' at 945015599 (100%) 2.06M/s eta:0s [Receiving data] \chunk 472507805-708761701 `video.mkv' at 703686045 (97%) 1.92M/s eta:3s [Receiving data] \chunk 236253908-472507804 `video.mkv' at 449737428 (90%) 1.87M/s eta:13s [Receiving data]
2020/06/08 12:31:36 - ERROR - seedsync.ControllerJob - Caught exception in job ControllerJob
Traceback (most recent call last):
File "/app/python/lftp/job_status_parser.py", line 81, in parse
statuses += self.__parse_queue(lines)
File "/app/python/lftp/job_status_parser.py", line 486, in __parse_queue
raise ValueError("Missing queue header line 1: {}".format(line))
ValueError: Missing queue header line 1: 2020-06-08 19:31:36 sftp://username@domain.com/path/video.mkv -> /path/video.mkv.lftp 708761702-945015599 1.87 MiB/s

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/app/python/common/job.py", line 44, in run
self.execute()
File "/app/python/controller/controller_job.py", line 29, in execute
self.__controller.process()
File "/app/python/controller/controller.py", line 202, in process
self.__update_model()
File "/app/python/controller/controller.py", line 295, in __update_model
lftp_statuses = self.__lftp.status()
File "/app/python/lftp/lftp.py", line 314, in status
statuses = self.__job_status_parser.parse(statuses_str)
File "/app/python/lftp/job_status_parser.py", line 86, in parse
raise LftpJobStatusParserError("Error parsing lftp job status")
lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status
2020/06/08 12:31:36 - DEBUG - seedsync.ControllerJob - Calling cleanup for ControllerJob
2020/06/08 12:31:36 - DEBUG - seedsync.Controller - Exiting controller
2020/06/08 12:31:36 - ERROR - seedsync - Caught exception
Traceback (most recent call last):
File "/app/python/lftp/job_status_parser.py", line 81, in parse
statuses += self.__parse_queue(lines)
File "/app/python/lftp/job_status_parser.py", line 486, in __parse_queue
raise ValueError("Missing queue header line 1: {}".format(line))
ValueError: Missing queue header line 1: 2020-06-08 19:31:36 sftp://username@domain.com/path/video.mkv -> /path/video.mkv.lftp 708761702-945015599 1.87 MiB/s

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/app/python/seedsync.py", line 162, in run
controller_job.propagate_exception()
File "/app/python/common/job.py", line 77, in propagate_exception
raise exc_info[1].with_traceback(exc_info[2])
File "/app/python/common/job.py", line 44, in run
self.execute()
File "/app/python/controller/controller_job.py", line 29, in execute
self.__controller.process()
File "/app/python/controller/controller.py", line 202, in process
self.__update_model()
File "/app/python/controller/controller.py", line 295, in __update_model
lftp_statuses = self.__lftp.status()
File "/app/python/lftp/lftp.py", line 314, in status
statuses = self.__job_status_parser.parse(statuses_str)
File "/app/python/lftp/job_status_parser.py", line 86, in parse
raise LftpJobStatusParserError("Error parsing lftp job status")
lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status
ipsingh06 commented 4 years ago

Thanks for the logs guys. It will be fixed soon in the next version.

ipsingh06 commented 4 years ago

Please try the newest version v0.8.0.

markhalliwell commented 4 years ago

So far this looks promising :D

I'll have to see how it performs over the next couple of days.

markhalliwell commented 4 years ago

I'll go ahead and close this as any new errors would likely be a separate issue anyway.

markhalliwell commented 4 years ago

Nope. Still happening (albeit less frequently):

2020/06/15 09:33:10 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - LftpJobStateParser error: Missing queue header line 1: /downloads/(redacted).mp4.lftp 1288777143-1369325714 220.3 KiB/s
2020/06/15 09:33:10 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - Status: /downloads/(redacted).mp4.lftp 1288777143-1369325714 220.3 KiB/s jobs -v [0] queue (sftp://(redacted)) -- 14.74 MiB/s sftp://(redacted) Now executing: [1] mirror -c (redacted) /downloads/ -- 22G/25G (88%) 14.74 MiB/s [1] mirror -c (redacted) /downloads/ -- 22G/25G (88%) 14.74 MiB/s \mirror `(redacted)' -- 2.0G/2.1G (98%) 1.29 MiB/s \transfer `(redacted).mp4' `(redacted).mp4', got 1993308451 of 2013714282 (98%) 1.29M/s eta:24s \chunk 1369325714-1449874284 `(redacted).mp4' at 1445740690 (94%) 231.7K/s eta:18s [Receiving data] \chunk 1208228572-1288777142 `(redacted).mp4' at 1285364444 (95%) 209.2K/s eta:15s [Receiving data] \chunk 805485717-886034287 `(redacted).mp4' at 882392213 (95%) 209.6K/s eta:16s [Receiving data] \chunk 724937146-805485716 `(redacted).mp4' at 799451578 (92%) 393.1K/s eta:24s [Receiving data] \chunk 563840004-644388574 `(redacted).mp4' at 641205252 (96%) 276.0K/s eta:13s [Receiving data] \mirror `(redacted)' -- 3.0G/5.9G (50%) 13.45 MiB/s \transfer `(redacted).mkv' `(redacted).mkv', got 2980151296 of 5871398815 (50%) 13.45M/s eta:14m \chunk 0-234855967 `(redacted).mkv' at 96305152 (1%) 461.2K/s eta:6m [Receiving data] \chunk 5636542863-5871398814 `(redacted).mkv' at 5811425679 (74%) 568.1K/s eta:87s [Receiving data] \chunk 5401686911-5636542862 `(redacted).mkv' at 5497566079 (40%) 385.8K/s eta:6m [Receiving data] \chunk 5166830959-5401686910 `(redacted).mkv' at 5217752431 (21%) 227.8K/s eta:14m [Receiving data] \chunk 4931975007-5166830958 `(redacted).mkv' at 5084149599 (64%) 739.0K/s eta:2m [Receiving data] \chunk 4697119055-4931975006 `(redacted).mkv' at 4819573071 (52%) 461.5K/s eta:4m [Receiving data] \chunk 4462263103-4697119054 `(redacted).mkv' at 4544838463 (35%) 524.1K/s eta:6m [Receiving data] \chunk 4227407151-4462263102 `(redacted).mkv' at 4318305583 (38%) 577.9K/s eta:6m [Receiving data] \chunk 3992551199-4227407150 `(redacted).mkv' at 4170579743 (75%) 1000.3K/s eta:74s [Receiving data] \chunk 3757695247-3992551198 `(redacted).mkv' at 3855376655 (41%) 595.6K/s eta:5m [Receiving data] \chunk 3522839295-3757695246 `(redacted).mkv' at 3690808063 (71%) 824.3K/s eta:96s [Receiving data] \chunk 3287983343-3522839294 `(redacted).mkv' at 3436324079 (63%) 549.6K/s eta:2m [Receiving data] \chunk 3053127391-3287983342 `(redacted).mkv' at 3138455263 (36%) 521.5K/s eta:7m [Receiving data] \chunk 2818271439-3053127390 `(redacted).mkv' at 2907007183 (37%) 359.4K/s eta:6m [Receiving data] \chunk 2583415487-2818271438 `(redacted).mkv' at 2634042047 (21%) 294.7K/s eta:13m [Receiving data] \chunk 2348559535-2583415486 `(redacted).mkv' at 2550082735 (85%) 850.9K/s eta:41s [Receiving data] \chunk 2113703583-2348559534 `(redacted).mkv' at 2220854943 (45%) 501.2K/s eta:4m [Receiving data] \chunk 1878847631-2113703582 `(redacted).mkv' at 2024501391 (62%) 456.4K/s eta:2m [Receiving data] \chunk 1643991679-1878847630 `(redacted).mkv' at 1797706367 (65%) 697.2K/s eta:2m [Receiving data] \chunk 1409135727-1643991678 `(redacted).mkv' at 1551086703 (60%) 463.3K/s eta:3m [Receiving data] \chunk 1174279775-1409135726 `(redacted).mkv' at 1322882655 (63%) 739.4K/s eta:2m [Receiving data] \chunk 939423823-1174279774 `(redacted).mkv' at 1012004943 (30%) 387.3K/s eta:8m [Receiving data] \chunk 704567871-939423822 `(redacted).mkv' at 820369983 (49%) 635.2K/s eta:4m [Receiving data] \chunk 469711919-704567870 `(redacted).mkv' at 591084591 (51%) 540.7K/s eta:4m [Receiving data] \chunk 234855967-469711918 `(redacted).mkv' at 323853855 (37%) 408.8K/s eta:7m [Receiving data]
2020/06/15 09:33:10 - ERROR - seedsync.ControllerJob - Caught exception in job ControllerJob
Traceback (most recent call last):
File "/app/python/lftp/job_status_parser.py", line 85, in parse
statuses += self.__parse_queue(lines)
File "/app/python/lftp/job_status_parser.py", line 490, in __parse_queue
raise ValueError("Missing queue header line 1: {}".format(line))
ValueError: Missing queue header line 1: /downloads/(redacted).mp4.lftp 1288777143-1369325714 220.3 KiB/s

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/app/python/common/job.py", line 44, in run
self.execute()
File "/app/python/controller/controller_job.py", line 29, in execute
self.__controller.process()
File "/app/python/controller/controller.py", line 202, in process
self.__update_model()
File "/app/python/controller/controller.py", line 295, in __update_model
lftp_statuses = self.__lftp.status()
File "/app/python/lftp/lftp.py", line 309, in status
statuses = self.__job_status_parser.parse(out)
File "/app/python/lftp/job_status_parser.py", line 90, in parse
raise LftpJobStatusParserError("Error parsing lftp job status")
lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status
2020/06/15 09:33:11 - ERROR - seedsync - Caught exception
Traceback (most recent call last):
File "/app/python/lftp/job_status_parser.py", line 85, in parse
statuses += self.__parse_queue(lines)
File "/app/python/lftp/job_status_parser.py", line 490, in __parse_queue
raise ValueError("Missing queue header line 1: {}".format(line))
ValueError: Missing queue header line 1: /downloads/(redacted).mp4.lftp 1288777143-1369325714 220.3 KiB/s

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/app/python/seedsync.py", line 162, in run
controller_job.propagate_exception()
File "/app/python/common/job.py", line 77, in propagate_exception
raise exc_info[1].with_traceback(exc_info[2])
File "/app/python/common/job.py", line 44, in run
self.execute()
File "/app/python/controller/controller_job.py", line 29, in execute
self.__controller.process()
File "/app/python/controller/controller.py", line 202, in process
self.__update_model()
File "/app/python/controller/controller.py", line 295, in __update_model
lftp_statuses = self.__lftp.status()
File "/app/python/lftp/lftp.py", line 309, in status
statuses = self.__job_status_parser.parse(out)
File "/app/python/lftp/job_status_parser.py", line 90, in parse
raise LftpJobStatusParserError("Error parsing lftp job status")
lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status
2020/06/15 09:33:14 - INFO - seedsync.Controller - Exited controller
ipsingh06 commented 4 years ago

Could you please post the full second line only redacting the filenames. 2020/06/15 09:33:10 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - Status: (redacted) [Receiving data] I need to see the full status to see what's going wrong.

markhalliwell commented 4 years ago

updated

TheFeelTrain commented 4 years ago

It seemed like we had the same problem but mine has actually had no problems for the last week. Been smooth sailing since 0.8.0.

markhalliwell commented 4 years ago

Another crash, this had debug enabled though:

2020/06/17 07:42:12 - DEBUG - RemoteScanner - Scan took 2.360s
2020/06/17 07:42:12 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:42:12 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:13 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:13 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:14 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:14 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:15 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:16 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:16 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:17 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:17 - DEBUG - LocalScanner - Running a scan
2020/06/17 07:42:17 - DEBUG - LocalScanner - Scan took 0.058s
2020/06/17 07:42:17 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:18 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:18 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:19 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:20 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file '(redacted)'
2020/06/17 07:42:20 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - LftpJobStateParser error: Missing queue header line 1: /downloads/(redacted).mp4.lftp 914457562-997590066 436.5 KiB/s
2020/06/17 07:42:20 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - Status: /downloads/(redacted).mp4.lftp 914457562-997590066 436.5 KiB/s jobs -v [0] queue (sftp://(redacted)) -- 4.50 MiB/s sftp://(redacted) Now executing: [1] mirror -c (redacted) /downloads/ -- 2.1G/2.1G (97%) 4.50 MiB/s [1] mirror -c (redacted) /downloads/ -- 2.1G/2.1G (97%) 4.50 MiB/s \mirror `Fallen (1998)' \transfer `(redacted).mp4' `(redacted).mp4', got 2028635890 of 2078312618 (97%) 4.50M/s eta:32s \chunk 1496385090-1579517593 `(redacted).mp4' at 1567327810 (85%) 823.2K/s eta:29s [Receiving data] \chunk 1330120082-1413252585 `(redacted).mp4' at 1400046994 (84%) 735.7K/s eta:32s [Receiving data] \chunk 748192554-831325057 `(redacted).mp4' at 819200810 (85%) 787.2K/s eta:29s [Receiving data] \chunk 665060050-748192553 `(redacted).mp4' at 736985810 (86%) 891.7K/s eta:26s [Receiving data] \chunk 415662538-498795041 `(redacted).mp4' at 497844682 (98%) 1.33M/s eta:2s [Receiving data]
2020/06/17 07:42:20 - ERROR - seedsync.ControllerJob - Caught exception in job ControllerJob
Traceback (most recent call last):
File "/app/python/lftp/job_status_parser.py", line 85, in parse
statuses += self.__parse_queue(lines)
File "/app/python/lftp/job_status_parser.py", line 490, in __parse_queue
raise ValueError("Missing queue header line 1: {}".format(line))
ValueError: Missing queue header line 1: /downloads/(redacted).mp4.lftp 914457562-997590066 436.5 KiB/s

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/app/python/common/job.py", line 44, in run
self.execute()
File "/app/python/controller/controller_job.py", line 29, in execute
self.__controller.process()
File "/app/python/controller/controller.py", line 202, in process
self.__update_model()
File "/app/python/controller/controller.py", line 295, in __update_model
lftp_statuses = self.__lftp.status()
File "/app/python/lftp/lftp.py", line 309, in status
statuses = self.__job_status_parser.parse(out)
File "/app/python/lftp/job_status_parser.py", line 90, in parse
raise LftpJobStatusParserError("Error parsing lftp job status")
lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status
2020/06/17 07:42:20 - DEBUG - seedsync.ControllerJob - Calling cleanup for ControllerJob
2020/06/17 07:42:20 - DEBUG - seedsync.Controller - Exiting controller
2020/06/17 07:42:21 - DEBUG - ActiveScanner - Process received terminate flag
2020/06/17 07:42:21 - DEBUG - ActiveScanner - Exiting process
2020/06/17 07:42:21 - ERROR - seedsync - Caught exception
Traceback (most recent call last):
File "/app/python/lftp/job_status_parser.py", line 85, in parse
statuses += self.__parse_queue(lines)
File "/app/python/lftp/job_status_parser.py", line 490, in __parse_queue
raise ValueError("Missing queue header line 1: {}".format(line))
ValueError: Missing queue header line 1: /downloads/(redacted).mp4.lftp 914457562-997590066 436.5 KiB/s

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/app/python/seedsync.py", line 162, in run
controller_job.propagate_exception()
File "/app/python/common/job.py", line 77, in propagate_exception
raise exc_info[1].with_traceback(exc_info[2])
File "/app/python/common/job.py", line 44, in run
self.execute()
File "/app/python/controller/controller_job.py", line 29, in execute
self.__controller.process()
File "/app/python/controller/controller.py", line 202, in process
self.__update_model()
File "/app/python/controller/controller.py", line 295, in __update_model
lftp_statuses = self.__lftp.status()
File "/app/python/lftp/lftp.py", line 309, in status
statuses = self.__job_status_parser.parse(out)
File "/app/python/lftp/job_status_parser.py", line 90, in parse
raise LftpJobStatusParserError("Error parsing lftp job status")
lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status
2020/06/17 07:42:24 - DEBUG - ExtractProcess - Process received terminate flag
2020/06/17 07:42:24 - DEBUG - seedsync.Controller.MPLogger - Stopped listener thread
2020/06/17 07:42:24 - INFO - seedsync.Controller - Exited controller
2020/06/17 07:42:24 - DEBUG - seedsync.ControllerJob - Finished cleanup for ControllerJob
2020/06/17 07:42:24 - DEBUG - seedsync.ControllerJob - Thread ControllerJob stopped
2020/06/17 07:42:42 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:43:17 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:43:42 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:44:12 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:44:42 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:45:18 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:45:42 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:46:12 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:46:48 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:47:13 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:47:43 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:48:16 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:48:43 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:49:13 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:49:43 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:50:16 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:50:43 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:51:13 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:51:47 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:52:13 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:52:43 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:53:17 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:53:43 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:54:13 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:54:47 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:55:13 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:55:43 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:56:18 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:56:43 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:57:13 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:57:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:58:18 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 07:58:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:59:14 - DEBUG - seedsync - Persisting states to file
2020/06/17 07:59:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:00:18 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:00:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:01:14 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:01:47 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:02:14 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:02:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:03:18 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:03:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:04:14 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:04:48 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:05:14 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:05:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:06:14 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:06:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:07:14 - DEBUG - seedsync.WebApp - Stream connection stopped by client
2020/06/17 08:07:14 - DEBUG - seedsync.Controller.Model - LftpModel: Removing a listener
2020/06/17 08:07:17 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:07:44 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:08:14 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:08:45 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:09:20 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:09:45 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:10:15 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:10:45 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:11:19 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:11:45 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:12:15 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:12:49 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:13:15 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:13:45 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:14:19 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:14:45 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:15:15 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:15:48 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:16:15 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:16:45 - DEBUG - seedsync - Persisting states to file
2020/06/17 08:17:15 - DEBUG - seedsync.WebApp - Stream connection stopped by client
2020/06/17 08:17:15 - DEBUG - seedsync.Controller.Model - LftpModel: Removing a listener
2020/06/17 08:17:18 - DEBUG - seedsync.Controller.Model - LftpModel: Adding a listener
2020/06/17 08:17:45 - DEBUG - seedsync - Persisting states to file
ipsingh06 commented 4 years ago

Thanks Mark for the logs. I have never seen this case before but I'll add a handler for it.

ipsingh06 commented 4 years ago

Mark try v0.8.1

markhalliwell commented 4 years ago

Ok. Trying now.

Jencryzthers commented 4 years ago

I still have some parsing issue here im running the last version Let me know if you need more detail.

I took this screenshot of the error while having debug on. Screen Shot 2020-06-25 at 4 06 31 PM

ipsingh06 commented 4 years ago

@Jencryzthers Could you please send me a few of the messages before this error. This screenshot does not include the status line which I need to understand the failure. Thanks.

Jencryzthers commented 4 years ago

I reproduced the error and redacted a few line. Let me know if this is enough.

`2020/06/29 18:55:09 - DEBUG - LocalScanner - Scan took 3.306s 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:09 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted' 2020/06/29 18:55:10 - WARNING - ActiveScanner.ActiveScanner - Path does not exist: /downloads/redacted 2020/06/29 18:55:10 - WARNING - ActiveScanner.ActiveScanner - Path does not exist: /downloads/redacted 2020/06/29 18:55:10 - WARNING - ActiveScanner.ActiveScanner - Path does not exist: /downloads/redacted 2020/06/29 18:55:10 - WARNING - ActiveScanner.ActiveScanner - Path does not exist: /downloads/redacted 2020/06/29 18:55:11 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - LftpJobStateParser error: Unable to parse line '[8] pget -c /media/sdq1/home/jencryzthers/private/deluge/data/sync/The.Redacted.Redacted.2020.Multi.10jobs -v' 2020/06/29 18:55:11 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - Status: jobs -v [0] queue (sftp://redacted@feralhosting.com:22) -- 29.12 MiB/s sftp://redacted@feralhosting.com:22/media/sdq1/home/jencryzthers 2020/06/29 18:55:11 - ERROR - seedsync.ControllerJob - Caught exception in job ControllerJob Traceback (most recent call last): File "/app/python/lftp/job_status_parser.py", line 90, in parse statuses += self.__parse_jobs(lines) File "/app/python/lftp/job_status_parser.py", line 472, in __parse_jobs raise ValueError("Unable to parse line '{}'".format(line)) ValueError: Unable to parse line '[8] pget -c /media/sdq1/home/jencryzthers/private/deluge/data/sync/The.Redacted.Redacted.2020.Multi.10jobs -v'

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/app/python/common/job.py", line 44, in run self.execute() File "/app/python/controller/controller_job.py", line 29, in execute self.controller.process() File "/app/python/controller/controller.py", line 202, in process self.update_model() File "/app/python/controller/controller.py", line 295, in update_model lftp_statuses = self.lftp.status() File "/app/python/lftp/lftp.py", line 316, in status statuses = self.job_status_parser.parse(out) File "/app/python/lftp/job_status_parser.py", line 94, in parse raise LftpJobStatusParserError("Error parsing lftp job status") lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status 2020/06/29 18:55:11 - DEBUG - seedsync.ControllerJob - Calling cleanup for ControllerJob 2020/06/29 18:55:11 - DEBUG - seedsync.Controller - Exiting controller 2020/06/29 18:55:11 - WARNING - ActiveScanner.ActiveScanner - Path does not exist: /downloads/redacted 2020/06/29 18:55:11 - WARNING - ActiveScanner.ActiveScanner - Path does not exist: /downloads/redacted 2020/06/29 18:55:11 - WARNING - ActiveScanner.ActiveScanner - Path does not exist: /downloads/redacted 2020/06/29 18:55:11 - WARNING - ActiveScanner.ActiveScanner - Path does not exist: /downloads/redacted 2020/06/29 18:55:11 - ERROR - seedsync - Caught exception Traceback (most recent call last): File "/app/python/lftp/job_status_parser.py", line 90, in parse statuses += self.parse_jobs(lines) File "/app/python/lftp/job_status_parser.py", line 472, in __parse_jobs raise ValueError("Unable to parse line '{}'".format(line)) ValueError: Unable to parse line '[8] pget -c /media/sdq1/home/jencryzthers/private/deluge/data/sync/The.Redacted.Redacted.2020.Multi.10jobs -v'

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/app/python/seedsync.py", line 162, in run controller_job.propagate_exception() File "/app/python/common/job.py", line 77, in propagate_exception raise exc_info[1].with_traceback(exc_info[2]) File "/app/python/common/job.py", line 44, in run self.execute() File "/app/python/controller/controller_job.py", line 29, in execute self.controller.process() File "/app/python/controller/controller.py", line 202, in process self.update_model() File "/app/python/controller/controller.py", line 295, in update_model lftp_statuses = self.lftp.status() File "/app/python/lftp/lftp.py", line 316, in status statuses = self.__job_status_parser.parse(out) File "/app/python/lftp/job_status_parser.py", line 94, in parse raise LftpJobStatusParserError("Error parsing lftp job status") lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status`

ipsingh06 commented 4 years ago

Please try version 0.8.3.

Jencryzthers commented 4 years ago

I just updated and now it is unable to retrive anything. I tested using manual lftp command and it works.

Here is the log

2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:52 - DEBUG - seedsync.Controller.Model - LftpModel: Updating file 'redacted.mkv' 2020/06/30 10:29:56 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "/app/python/lftp/lftp.py", line 128, in run_command self.process.expect(self.expect_pattern, timeout=self.timeout) File "/usr/local/lib/python3.7/dist-packages/pexpect/spawnbase.py", line 344, in expect timeout, searchwindowsize, async_) File "/usr/local/lib/python3.7/dist-packages/pexpect/spawnbase.py", line 372, in expect_list return exp.expect_loop(timeout) File "/usr/local/lib/python3.7/dist-packages/pexpect/expect.py", line 181, in expect_loop return self.timeout(e) File "/usr/local/lib/python3.7/dist-packages/pexpect/expect.py", line 144, in timeout raise exc pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x14fdf0f15a10> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'jencryzthers,{redacted}', 'sftp://{redacted}.feralhosting.com'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 7 child_fd: 5 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp jencryzthers@{redacted}.feralhosting.com:.*>') 2020/06/30 10:29:57 - DEBUG - RemoteScanner - Running a scan 2020/06/30 10:29:57 - DEBUG - RemoteScanner.RemoteScanner.Sshcp - Command: ssh -p 22 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o LogLevel=error -o PubkeyAuthentication=no jencryzthers@{redacted}.feralhosting.com "'/tmp/scanfs' '/media/sdq1/home/jencryzthers/private/deluge/data/sync'" 2020/06/30 10:29:57 - DEBUG - LocalScanner - Running a scan 2020/06/30 10:29:57 - DEBUG - seedsync - Persisting states to file 2020/06/30 10:29:57 - DEBUG - LocalScanner - Scan took 0.369s

ipsingh06 commented 4 years ago

@Jencryzthers Did you try this again? Are you using the docker image or the debian package? Also what operating system are you installing SeedSync on?

Jencryzthers commented 4 years ago

@ipsingh06 I use unRaid with docker

I wiped everything and tried again with the last version.

here is the new error log

2020/07/04 12:41:24 - INFO - seedsync.ServerActionHandler - Received a restart action 2020/07/04 12:41:24 - INFO - seedsync - Exiting Seedsync 2020/07/04 12:41:31 - INFO - RemoteScanner.RemoteScanner - Skipping remote scanfs installation: already installed 2020/07/04 12:41:38 - INFO - seedsync.AutoQueue - Auto queueing 'redacted' 2020/07/04 12:41:45 - INFO - seedsync.Controller - Received command Action.QUEUE for file redacted 2020/07/04 12:42:20 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "/app/python/lftp/lftp.py", line 128, in run_command self.process.expect(self.expect_pattern, timeout=self.timeout) File "/usr/local/lib/python3.7/dist-packages/pexpect/spawnbase.py", line 344, in expect timeout, searchwindowsize, async_) File "/usr/local/lib/python3.7/dist-packages/pexpect/spawnbase.py", line 372, in expect_list return exp.expect_loop(timeout) File "/usr/local/lib/python3.7/dist-packages/pexpect/expect.py", line 181, in expect_loop return self.timeout(e) File "/usr/local/lib/python3.7/dist-packages/pexpect/expect.py", line 144, in timeout raise exc pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x15187f492790> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'jencryzthers,redacted', 'sftp://redacted.feralhosting.com'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 20 child_fd: 30 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp jencryzthers@redacted.feralhosting.com:.*>') 2020/07/04 12:42:24 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - LftpJobStateParser error: Unable to parse line '0 (23%) 1.98M/s eta:2m [Receiving data]' 2020/07/04 12:42:24 - ERROR - seedsync.Controller.Lftp.LftpJobStatusParser - Status: jobs -v [0] queue (sftp://jencryzthers:redacted@redacted.feralhosting.com:22) -- 16.34 MiB/s 2020/07/04 12:42:25 - ERROR - seedsync.ControllerJob - Caught exception in job ControllerJob Traceback (most recent call last): File "/app/python/lftp/job_status_parser.py", line 90, in parse statuses += self.__parse_jobs(lines) File "/app/python/lftp/job_status_parser.py", line 472, in __parse_jobs raise ValueError("Unable to parse line '{}'".format(line)) ValueError: Unable to parse line '2 (23%) 1.86M/s eta:2m [Receiving data]'

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/app/python/common/job.py", line 44, in run self.execute() File "/app/python/controller/controller_job.py", line 29, in execute self.controller.process() File "/app/python/controller/controller.py", line 202, in process self.update_model() File "/app/python/controller/controller.py", line 295, in update_model lftp_statuses = self.lftp.status() File "/app/python/lftp/lftp.py", line 322, in status statuses = self.job_status_parser.parse(out) File "/app/python/lftp/job_status_parser.py", line 94, in parse raise LftpJobStatusParserError("Error parsing lftp job status") lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status 2020/07/04 12:42:26 - ERROR - seedsync - Caught exception Traceback (most recent call last): File "/app/python/lftp/job_status_parser.py", line 90, in parse statuses += self.parse_jobs(lines) File "/app/python/lftp/job_status_parser.py", line 472, in __parse_jobs raise ValueError("Unable to parse line '{}'".format(line)) ValueError: Unable to parse line '2 (23%) 1.86M/s eta:2m [Receiving data]'

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/app/python/seedsync.py", line 162, in run controller_job.propagate_exception() File "/app/python/common/job.py", line 77, in propagate_exception raise exc_info[1].with_traceback(exc_info[2]) File "/app/python/common/job.py", line 44, in run self.execute() File "/app/python/controller/controller_job.py", line 29, in execute self.controller.process() File "/app/python/controller/controller.py", line 202, in process self.update_model() File "/app/python/controller/controller.py", line 295, in update_model lftp_statuses = self.lftp.status() File "/app/python/lftp/lftp.py", line 322, in status statuses = self.__job_status_parser.parse(out) File "/app/python/lftp/job_status_parser.py", line 94, in parse raise LftpJobStatusParserError("Error parsing lftp job status") lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status 2020/07/04 12:42:27 - INFO - seedsync.Controller - Exited controller

ipsingh06 commented 4 years ago

@Jencryzthers I'm not able to tell what's going wrong from those logs. Please do the following to enable verbose logging. In your settings.cfg file, change verbose = False to verbose = True. Then run it again and send the logs. Thanks.

markhalliwell commented 4 years ago

I haven't seen any more issues. I think this can be closed now. I think the issue @Jencryzthers is having is seemingly unrelated to this one as it throws a timeout exception prior to the parsing one.

ipsingh06 commented 4 years ago

@Jencryzthers Could you please create a new ticket with the verbose logs, thanks.

CasaPas commented 2 years ago

I have docker 0.8.6 and hitting the same error. Restarting resolves the app for a random period of time (could be minutes, could be hours)

CasaPas commented 2 years ago

Log Dump:

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/app/python/common/job.py", line 44, in run self.execute() File "/app/python/controller/controller_job.py", line 29, in execute self.controller.process() File "/app/python/controller/controller.py", line 202, in process self.update_model() File "/app/python/controller/controller.py", line 295, in update_model lftp_statuses = self.lftp.status() File "/app/python/lftp/lftp.py", line 322, in status statuses = self.job_status_parser.parse(out) File "/app/python/lftp/job_status_parser.py", line 94, in parse raise LftpJobStatusParserError("Error parsing lftp job status") lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status 2022-06-04 12:59:42,020 - ERROR - seedsync (MainProcess/MainThread) - Caught exception Traceback (most recent call last): File "/app/python/lftp/job_status_parser.py", line 89, in parse statuses += self.parse_queue(lines) File "/app/python/lftp/job_status_parser.py", line 482, in __parse_queue raise ValueError("Unrecognized line '{}'".format(lines[0])) ValueError: Unrecognized line '/downloads/AudioBook/1984 (George Orwell) - Audio Book/Audio Books - George Orwell - 1984 - 6 of 14.mp3.lftp 7813120-11719680 34.4 KiB/s'

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/app/python/seedsync.py", line 164, in run controller_job.propagate_exception() File "/app/python/common/job.py", line 77, in propagate_exception raise exc_info[1].with_traceback(exc_info[2]) File "/app/python/common/job.py", line 44, in run self.execute() File "/app/python/controller/controller_job.py", line 29, in execute self.controller.process() File "/app/python/controller/controller.py", line 202, in process self.update_model() File "/app/python/controller/controller.py", line 295, in update_model lftp_statuses = self.lftp.status() File "/app/python/lftp/lftp.py", line 322, in status statuses = self.job_status_parser.parse(out) File "/app/python/lftp/job_status_parser.py", line 94, in parse raise LftpJobStatusParserError("Error parsing lftp job status") lftp.job_status_parser.LftpJobStatusParserError: Error parsing lftp job status 2022-06-04 12:59:45,037 - ERROR - seedsync.Controller.Lftp (MainProcess/ControllerJob) - Lftp timeout exception Traceback (most recent call last): File "/app/python/lftp/lftp.py", line 128, in run_command self.process.expect(self.expect_pattern, timeout=self.timeout) File "/usr/local/lib/python3.8/site-packages/pexpect/spawnbase.py", line 343, in expect return self.expect_list(compiled_pattern_list, File "/usr/local/lib/python3.8/site-packages/pexpect/spawnbase.py", line 372, in expect_list return exp.expect_loop(timeout) File "/usr/local/lib/python3.8/site-packages/pexpect/expect.py", line 181, in expect_loop return self.timeout(e) File "/usr/local/lib/python3.8/site-packages/pexpect/expect.py", line 144, in timeout raise exc pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x14b62a98ca90> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', ‘XXX,XXX’, 'sftp://XXX’] buffer (last 100 chars): b'll) - Audio Book/Audio Books - George Orwell - 1984 - 6 of 14.mp3.lftp 7813120-11719680 34.4 KiB/s\r\n' before (last 100 chars): b'll) - Audio Book/Audio Books - George Orwell - 1984 - 6 of 14.mp3.lftp 7813120-11719680 34.4 KiB/s\r\n' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 714 child_fd: 68 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXX@XXXX:.*>’) 2022-06-04 12:59:48,092 - ERROR - seedsync.Controller.Lftp (MainProcess/ControllerJob) - Lftp timeout exception Traceback (most recent call last): File "/app/python/lftp/lftp.py", line 128, in __run_command self.process.expect(self.__expect_pattern, timeout=self.__timeout) File "/usr/local/lib/python3.8/site-packages/pexpect/spawnbase.py", line 343, in expect return self.expect_list(compiled_pattern_list, File "/usr/local/lib/python3.8/site-packages/pexpect/spawnbase.py", line 372, in expect_list return exp.expect_loop(timeout) File "/usr/local/lib/python3.8/site-packages/pexpect/expect.py", line 181, in expect_loop return self.timeout(e) File "/usr/local/lib/python3.8/site-packages/pexpect/expect.py", line 144, in timeout raise exc pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x14b62a98ca90> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', ‘XXX,XXX’, 'sftp://XXX’] buffer (last 100 chars): b'll) - Audio Book/Audio Books - George Orwell - 1984 - 6 of 14.mp3.lftp 7813120-11719680 34.4 KiB/s\r\n' before (last 100 chars): b'll) - Audio Book/Audio Books - George Orwell - 1984 - 6 of 14.mp3.lftp 7813120-11719680 34.4 KiB/s\r\n' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 714 child_fd: 68 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXX:.*>’) Exception in thread ControllerJob: Traceback (most recent call last): File "/usr/local/lib/python3.8/site-packages/pexpect/pty_spawn.py", line 23, in _wrap_ptyprocess_err yield File "/usr/local/lib/python3.8/site-packages/pexpect/pty_spawn.py", line 328, in close self.ptyproc.close(force=force) File "/usr/local/lib/python3.8/site-packages/ptyprocess/ptyprocess.py", line 400, in close raise PtyProcessError('Could not terminate the child.') ptyprocess.util.PtyProcessError: Could not terminate the child.

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner self.run() File "/app/python/common/job.py", line 56, in run self.cleanup() File "/app/python/controller/controller_job.py", line 34, in cleanup self.controller.exit() File "/app/python/controller/controller.py", line 207, in exit self.lftp.exit() File "/app/python/lftp/lftp.py", line 404, in exit self.__process.close(force=True) File "/usr/local/lib/python3.8/site-packages/pexpect/pty_spawn.py", line 328, in close self.ptyproc.close(force=force) File "/usr/local/lib/python3.8/contextlib.py", line 131, in exit self.gen.throw(type, value, traceback) File "/usr/local/lib/python3.8/site-packages/pexpect/pty_spawn.py", line 25, in _wrap_ptyprocess_err raise ExceptionPexpect(*e.args) pexpect.exceptions.ExceptionPexpect: Could not terminate the child.