Bug 1793594

Summary: Sessions from an rsync or scp command get corrupted
Product: Red Hat Enterprise Linux 8 Reporter: Lucas Caparelli <lcaparel>
Component: cockpit-session-recordingAssignee: jstephen
Status: CLOSED ERRATA QA Contact: Ondrej Moriš <omoris>
Severity: medium Docs Contact:
Priority: medium    
Version: 8.1CC: jstephen, nikolai.kondrashov, omoris, pkettman, sgoveas, spoore, sssd-qe
Target Milestone: rcFlags: pm-rhel: mirror+
Target Release: 8.3   
Hardware: Unspecified   
OS: Linux   
Whiteboard: sync-to-jira
Fixed In Version: cockpit-session-recording-4-2.el8 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-11-04 03:28:14 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1751783    
Bug Blocks:    

Description Lucas Caparelli 2020-01-21 16:03:53 UTC
Description of problem:

When performing a file transfer from a system with session recording enabled using rsync or scp the recording appears to get corrupted. Transferring files _to_ the system doesn't seem to be a problem.

Attempting to reproduce the recording in cockpit renders "SyntaxError: JSON.parse: unexpected non-whitespace character after JSON data at line 1 column 4 of the JSON data"

Attempting to use tlog-play also fails:

>>>>>
[root@rhel81-reproducer-session-rec test]# LC_ALL="en_US.UTF8" tlog-play -r journal

unexpected character
Failed reading the source at entry 0
>>>>>

Version-Release number of selected component (if applicable):

tlog-6-1.el8.x86_64

How reproducible:

Easily

Steps to Reproduce:

1. Set up file to be transferred from the system with session recordings enabled;
2. From another system download that file using rsync:

  # rsync <user>@<system>:/path/to/file .

  OR

  # scp <user>@<system>:/path/to/file .

Make sure the file doesn't already exist on the destination if using rsync. rsync performs incremental transfers, so if the file is already present it won't perform the transfer and the issue won't be reproduced (the session recording will be taken though, just not corrupted).


Actual results:

Recording gets corrupted.

Expected results:

Recording does not get corrupted.

Additional info:

It seems that due to the nature of how the recordings are loaded into cockpit no subsequent recordings are displayed (i.e. don't appear at the 'session recordings' dashboard). It would seem that subsequent sessions do get recorded as they appear on the logs, cockpit just can't seem to load anything else once it hits the bad entry.

Removing the journal file containing the bad entry allows for other recordings to appear.

Reproducer configuration uses default tlog configuration with sssd:

>>>>>
[root@rhel81-reproducer-session-rec test]# cat /etc/sssd/conf.d/sssd-session-recording.conf 
[session_recording]
scope=all
users=
groups=
>>>>>

Also noteworthy is that the transfer _from_ the system seem to be throttled somehow, but transfer _to_ the system are not. Please note the following output comes from two VMs in the same host.

>>>>>
[root@rhel77 ~]# scp test.122.157:/home/test/test_file .
test.122.157's password: 
Locale charset is ANSI_X3.4-1968 (ASCII)
Assuming locale environment is lost and charset is UTF-8

ATTENTION! Your session is being recorded!

test_file                                             100%   12MB   3.2MB/s   00:03    
[root@rhel77 ~]# scp test_file test.122.157:/home/test/
test.122.157's password: 
Locale charset is ANSI_X3.4-1968 (ASCII)
Assuming locale environment is lost and charset is UTF-8

ATTENTION! Your session is being recorded!

test_file                                             100%   12MB  62.7MB/s   00:00    
>>>>>

Comment 1 jstephen 2020-01-22 19:45:15 UTC
Thank you for reporting this issue, I will see if I can reproduce it on my end.

Comment 3 jstephen 2020-03-20 19:10:01 UTC
Hello,

The following command will always generate the error below(sorry, we should improve the error message here):

    [root@rhel81-reproducer-session-rec test]# LC_ALL="en_US.UTF8" tlog-play -r journal

    unexpected character
    Failed reading the source at entry 0

Could you try playing back the recording after specifying the -M tlog-play argument as well? You can follow these steps:

 - Find the recording containing the issue with 'journalctl'

     # journalctl -o verbose -r

 - Copy the recording ID from the message field:

     "rec":"ab906f9803204c0193a8968029f2acb6-f1b-6a70b"

 - Use the recording ID in the tlog-play command:

  # tlog-play -r journal -M TLOG_REC=ab906f9803204c0193a8968029f2acb6-c80-525e9

Thank you.

-Justin

Comment 4 Lucas Caparelli 2020-03-23 12:21:36 UTC
(In reply to jstephen from comment #3)
Hello,

Thanks for looking into this Justin.

> The following command will always generate the error below(sorry, we should
> improve the error message here):
> 
>     [root@rhel81-reproducer-session-rec test]# LC_ALL="en_US.UTF8" tlog-play
> -r journal
> 
>     unexpected character
>     Failed reading the source at entry 0

I'm hitting that as well:

[root@rhel81 ~]# LC_ALL="en_US.UTF8" tlog-play -r journal

unexpected character
Failed reading the source at entry 0


> 
> Could you try playing back the recording after specifying the -M tlog-play
> argument as well? You can follow these steps:
> 
>  - Find the recording containing the issue with 'journalctl'
> 
>      # journalctl -o verbose -r
> 
>  - Copy the recording ID from the message field:
> 
>      "rec":"ab906f9803204c0193a8968029f2acb6-f1b-6a70b"
> 
>  - Use the recording ID in the tlog-play command:
> 
>   # tlog-play -r journal -M
> TLOG_REC=ab906f9803204c0193a8968029f2acb6-c80-525e9


Strangely this doesn't run into any issues and the recording is played back successfully. I don't have any locale config done, which is why I'm specifying the env variable prior to the execution of the command:

[root@rhel81 ~]# LC_ALL="en_US.UTF8" tlog-play -r journal -M TLOG_REC=3f020ba639fa4ed185b1bf33bae1fac0-631c-2077a
[vagrant@rhel81 ~]$ test
[vagrant@rhel81 ~]$ logout

[root@rhel81 ~]# 

Thanks!

Comment 5 jstephen 2020-03-23 17:25:19 UTC
Thank you Lucas. I believe this is a problem in the recordings list and playback of the recording in the cockpit web interface, and not in tlog itself. If you or the customer do not agree please let me know.

I'm re-assigning to the correct component and will continue investigation on my side.

Comment 6 Lucas Caparelli 2020-03-23 17:58:53 UTC
(In reply to jstephen from comment #5)
Hello Justin,

> Thank you Lucas. I believe this is a problem in the recordings list and
> playback of the recording in the cockpit web interface, and not in tlog
> itself. If you or the customer do not agree please let me know.

I'm a bit confused though. If "tlog-play -r journal" seems to run into issues then isn't there something wrong in tlog-play? Or is the issue specific to certain locale configurations?

Just for reference I've faced the same error with C.UTF8 as well:


[root@rhel81 ~]# LC_ALL="C.UTF8" tlog-play -r journal

unexpected character
Failed reading the source at entry 0


If cockpit uses a similar mechanism or even tlog-play itself underneath then couldn't this be potentially related?

Comment 7 jstephen 2020-03-23 18:14:15 UTC
(In reply to Lucas Caparelli from comment #6)
> (In reply to jstephen from comment #5)
> Hello Justin,
> 
> > Thank you Lucas. I believe this is a problem in the recordings list and
> > playback of the recording in the cockpit web interface, and not in tlog
> > itself. If you or the customer do not agree please let me know.
> 
> I'm a bit confused though. If "tlog-play -r journal" seems to run into
> issues then isn't there something wrong in tlog-play? Or is the issue
> specific to certain locale configurations?
> 
> Just for reference I've faced the same error with C.UTF8 as well:
> 
> 
> [root@rhel81 ~]# LC_ALL="C.UTF8" tlog-play -r journal
> 
> unexpected character
> Failed reading the source at entry 0


This tlog-play command will always fail, it requires a -M argument to identify the recording to look for. For example: "tlog-play -r journal -M TLOG_REC=3f020ba639fa4ed185b1bf33bae1fac0-631c-2077a"

> 
> 
> If cockpit uses a similar mechanism or even tlog-play itself underneath then
> couldn't this be potentially related?

Cockpit-session-recording does *not* execute tlog-play underneath, it has it's own code which is used to aggregate a list of recordings from the journal and playback those recordings. That is why I believe the problem is specific to cockpit-session-recording, assuming tlog-play is playing back the recording correctly(with the -r journal and -M TLOG_REC=$recid argument).

Comment 8 Lucas Caparelli 2020-03-23 18:25:39 UTC
(In reply to jstephen from comment #7)
> (In reply to Lucas Caparelli from comment #6)
> > (In reply to jstephen from comment #5)
> > Hello Justin,
> > 
> > > Thank you Lucas. I believe this is a problem in the recordings list and
> > > playback of the recording in the cockpit web interface, and not in tlog
> > > itself. If you or the customer do not agree please let me know.
> > 
> > I'm a bit confused though. If "tlog-play -r journal" seems to run into
> > issues then isn't there something wrong in tlog-play? Or is the issue
> > specific to certain locale configurations?
> > 
> > Just for reference I've faced the same error with C.UTF8 as well:
> > 
> > 
> > [root@rhel81 ~]# LC_ALL="C.UTF8" tlog-play -r journal
> > 
> > unexpected character
> > Failed reading the source at entry 0
> 
> 
> This tlog-play command will always fail, it requires a -M argument to
> identify the recording to look for. For example: "tlog-play -r journal -M
> TLOG_REC=3f020ba639fa4ed185b1bf33bae1fac0-631c-2077a"
> 
> > 
> > 
> > If cockpit uses a similar mechanism or even tlog-play itself underneath then
> > couldn't this be potentially related?
> 
> Cockpit-session-recording does *not* execute tlog-play underneath, it has
> it's own code which is used to aggregate a list of recordings from the
> journal and playback those recordings. That is why I believe the problem is
> specific to cockpit-session-recording, assuming tlog-play is playing back
> the recording correctly(with the -r journal and -M TLOG_REC=$recid argument).

Oh, I see, thanks for the explanation Justin!

Comment 9 jstephen 2020-04-21 19:58:09 UTC
After troubleshooting this further, I have determined this issue is actually 2 separate isolated issues(although one recording can cause both issues to present themselves). One issue in the cockpit-session-recording Player page and the other in the cockpit-session-recording Recordings List page.

1) Regarding the issue with the player page when a rsync transfer session recording generates the playback error: "SyntaxError: JSON.parse: unexpected non-whitespace character after JSON data at line 1 column 4 of the JSON data"
       
    - I fixed this upstream after reproducing the problem stated in the bugzilla description: https://github.com/Scribery/cockpit-session-recording/pull/39

2) Regarding the issue with the Recordings page not listing any newer recordings after a large recording is created:

    - Is a known issue which requires a fix by the cockpit team, as we are utilizing their API to retrieve a complete list of journal entries to parse for the Recordings list. The BZ open with the cockpit team to track this work is:  https://bugzilla.redhat.com/show_bug.cgi?id=1751783

I propose we use this BZ 1793594 to track issue number 1 described above. I will move this to POST status to be fixed in RHEL 8.3, but note the complete fix for the described problem will depend on the BZ #1751783 which has no timeframe estimation of completion.

Comment 10 jstephen 2020-05-26 18:31:11 UTC
*** Bug 1694846 has been marked as a duplicate of this bug. ***

Comment 17 errata-xmlrpc 2020-11-04 03:28:14 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (cockpit-session-recording bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:4741