File Copy Modules failing inconsistently


  • I have two categories of file copy modules, driver packages ranging from 200MB to 2.2GB, that unzip to C:\drivers, and a script package, 100MB, unzips to C:\users\admin\desktop

    I have one universal image of windows 10 pro, with many profiles for different machines. Each machine installs a driver package, priority 1 partition 3, and the scripts, priority 2 partition 3.

    If I leave the image profile in it's default deploy configuration, Create Partitions Method: Standard, but without modifying the export schema to select partition 3, then WIE downloads and attempts to apply the file copy modules to all 4 partitions, causing streams of errors as every file in the zip archive fails; however, after all this failure the drivers will sometimes be on partition 3 for DISM to install, and sometimes they won't.

    The streams of errors are not included in the logs, which is frustrating.

    Different models have different personalities in this regard, with Surface pro 7+s generally working, pro 6s generally not working, pro 5s being complete scattershot, and pro 4s somehow installing a bunch of motherboard firmware wrong, and nothing else. (not so wrong that they're bricked)

    If I configure the profile image as Standard, with partition 3 active, generally the deploy fails and the machine is not bootable, however when it doesn't fail the log is a lot less messy, below is a summary and the complete log from a Surface Pro 4 deployed as Standard with partition 3 active.

    This image functions correctly on other models, and the File Copy modules are configured identically to models that do successfully copy; with the zip archives created by entering the drive export folder, selecting all, rightclick -> send to -> compressed zip folder. I then move the zip archive to my desktop, test it with 7zip, 0 errors, upload it through the web interface, find it on the file server, and test it again with 7zip, 0 errors.

    Summary:

    1: Start
    40: Unregistered Model Match: Surface Pro 4_test
    70: Current Boot Order
        > The boot configuration data store could not be opened.
        > The volume for a file has been externally altered so that the opened file is no longer valid.
        
    76: Mount SMB share: Successful
    124: Processing Drive 0
        > Error not included in log: Clear-disk: Disk is already clear
    
    256: New Partition Table
        PartitionNumber DriveLetter     Offset          Size        Type
        --------------- -----------     ------          ----        ----
        1                               1048576         260 MB      System
        2                               273678336       16 MB       Reserved
        3                               290455552       237.72 GB   Basic
        4                R              255535874048    500 MB      Recovery
    
    286: Image Download for Drive 0 Partition 3
        > hd0\part3.winpe.wim to C:
    
    292: File Copy: Surface_Pro_4.zip to \Drivers\
        > Error not included in log: Expand-Archive: Central Directory Corrupt
        > DISM: Error 2: No driver packages were found at the specified path
    
    324: File Copy: Desktop.15.0.0.zip to \users\admin\desktop\
        > Error not included in log: Expand-Archive: Central Directory Corrupt
    
    326: Making System Bootable
        > The boot configuration data store could not be opened
        > The requested system device cannot be identified due to multiple indistinguishable devices potentially matching the identification criteria
    
    338: Closing Task
    

    C4_9D_ED_E6_0A_26-modelmatchdeploy.txt

    What am I missing to make File Copy Modules reliable?

    Edit, corrected expand-archive error
    surface pro 4 file copy error.jpg


  • I found the client scripts and modified wie_deploy.ps1 to leave the zip file in place; it is 0kb in size. This is why Expand-Archive is throwing a fault deep in it's dependencies.

    I'm still learning how to get exit codes from curl.exe in powershell. It should be possible to replace the call to curl.exe with Invoke-WebRequest but I will have to comprehend how all the arguments are being constructed to adapt them, it's not 1-to-1.

    I believe, not at all strongly, that curl.exe is completing without throwing an error code.

    Edit: checked all the server logs, nothing related

    Logs from today

    Application.log

    2023-12-20 00:15:45,397 [Worker #13] ERROR Toems_DataModel.RawSqlRepository You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near ') AND (a.provision_status = 8 OR a.provision_status = 6 OR a.provision_status = ' at line 1
    2023-12-20 00:30:45,666 [Worker #8] INFO Toems_Service.Workflows.FolderSync Replicating Storage To Com Server, images will be replicated after this task. theoCom1
    2023-12-20 00:30:48,608 [Worker #8] INFO Toems_Service.Workflows.FolderSync Finished Replicating Storage To Com Server theoCom1
    2023-12-20 00:30:48,609 [Worker #8] INFO Toems_Service.Workflows.ImageSync Starting Image Replication From Com Servers To SMB Share
    2023-12-20 00:30:48,611 [Worker #8] INFO Toems_Service.Workflows.ImageSync Image replication is not used when direct smb imaging is enabled.
    2023-12-20 00:30:48,612 [Worker #8] INFO Toems_Service.Workflows.ImageSync Starting Image Replication To Com Servers
    2023-12-20 00:30:48,614 [Worker #8] INFO Toems_Service.Workflows.ImageSync Image replication is not used when direct smb imaging is enabled.
    2023-12-20 00:30:48,614 [Worker #8] INFO Toems_Service.Workflows.FolderSync All replication tasks complete
    2023-12-20 03:15:06,181 [Worker #2] ERROR Toems_DataModel.RawSqlRepository You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near ') AND (a.provision_status = 8 OR a.provision_status = 6 OR a.provision_status = ' at line 1
    2023-12-20 04:00:07,691 [Worker #2] INFO Toems_Service.Workflows.DataCleanup Running Data Cleanup Job
    2023-12-20 04:00:07,763 [Worker #2] INFO Toems_Service.Workflows.DataCleanup Completed Data Cleanup Job
    2023-12-20 04:30:08,725 [Worker #9] INFO Toems_Service.Workflows.FolderSync Replicating Storage To Com Server, images will be replicated after this task. theoCom1
    2023-12-20 04:30:11,685 [Worker #9] INFO Toems_Service.Workflows.FolderSync Finished Replicating Storage To Com Server theoCom1
    2023-12-20 04:30:11,687 [Worker #9] INFO Toems_Service.Workflows.ImageSync Starting Image Replication From Com Servers To SMB Share
    2023-12-20 04:30:11,689 [Worker #9] INFO Toems_Service.Workflows.ImageSync Image replication is not used when direct smb imaging is enabled.
    2023-12-20 04:30:11,689 [Worker #9] INFO Toems_Service.Workflows.ImageSync Starting Image Replication To Com Servers
    2023-12-20 04:30:11,691 [Worker #9] INFO Toems_Service.Workflows.ImageSync Image replication is not used when direct smb imaging is enabled.
    2023-12-20 04:30:11,691 [Worker #9] INFO Toems_Service.Workflows.FolderSync All replication tasks complete
    2023-12-20 06:15:00,442 [Worker #9] ERROR Toems_DataModel.RawSqlRepository You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near ') AND (a.provision_status = 8 OR a.provision_status = 6 OR a.provision_status = ' at line 1
    2023-12-20 08:30:46,926 [Worker #16] INFO Toems_Service.Workflows.FolderSync Replicating Storage To Com Server, images will be replicated after this task. theoCom1
    2023-12-20 08:30:49,875 [Worker #16] INFO Toems_Service.Workflows.FolderSync Finished Replicating Storage To Com Server theoCom1
    2023-12-20 08:30:49,876 [Worker #16] INFO Toems_Service.Workflows.ImageSync Starting Image Replication From Com Servers To SMB Share
    2023-12-20 08:30:49,878 [Worker #16] INFO Toems_Service.Workflows.ImageSync Image replication is not used when direct smb imaging is enabled.
    2023-12-20 08:30:49,879 [Worker #16] INFO Toems_Service.Workflows.ImageSync Starting Image Replication To Com Servers
    2023-12-20 08:30:49,880 [Worker #16] INFO Toems_Service.Workflows.ImageSync Image replication is not used when direct smb imaging is enabled.
    2023-12-20 08:30:49,881 [Worker #16] INFO Toems_Service.Workflows.FolderSync All replication tasks complete
    2023-12-20 09:15:33,458 [Worker #18] ERROR Toems_DataModel.RawSqlRepository You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near ') AND (a.provision_status = 8 OR a.provision_status = 6 OR a.provision_status = ' at line 1
    2023-12-20 12:15:09,537 [Worker #2] ERROR Toems_DataModel.RawSqlRepository You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near ') AND (a.provision_status = 8 OR a.provision_status = 6 OR a.provision_status = ' at line 1
    2023-12-20 12:30:10,043 [Worker #12] INFO Toems_Service.Workflows.FolderSync Replicating Storage To Com Server, images will be replicated after this task. theoCom1
    2023-12-20 12:30:12,975 [Worker #12] INFO Toems_Service.Workflows.FolderSync Finished Replicating Storage To Com Server theoCom1
    2023-12-20 12:30:12,977 [Worker #12] INFO Toems_Service.Workflows.ImageSync Starting Image Replication From Com Servers To SMB Share
    2023-12-20 12:30:12,979 [Worker #12] INFO Toems_Service.Workflows.ImageSync Image replication is not used when direct smb imaging is enabled.
    2023-12-20 12:30:12,979 [Worker #12] INFO Toems_Service.Workflows.ImageSync Starting Image Replication To Com Servers
    2023-12-20 12:30:12,981 [Worker #12] INFO Toems_Service.Workflows.ImageSync Image replication is not used when direct smb imaging is enabled.
    2023-12-20 12:30:12,981 [Worker #12] INFO Toems_Service.Workflows.FolderSync All replication tasks complete
    

    Frontend.log

    No entries from today

    ClientAPI.log

    2023-12-20 00:30:48,125 [67] INFO Toems_Service.Workflows.FolderSync Replicating Folder client_versions From \\10.0.0.31\theo\client_versions to \\10.0.0.31\theo\client_versions on theoCom1
    2023-12-20 00:30:48,352 [67] INFO Toems_Service.Workflows.FolderSync Replicating Folder software_uploads From \\10.0.0.31\theo\software_uploads to \\10.0.0.31\theo\software_uploads on theoCom1
    2023-12-20 04:30:11,201 [25] INFO Toems_Service.Workflows.FolderSync Replicating Folder client_versions From \\10.0.0.31\theo\client_versions to \\10.0.0.31\theo\client_versions on theoCom1
    2023-12-20 04:30:11,431 [25] INFO Toems_Service.Workflows.FolderSync Replicating Folder software_uploads From \\10.0.0.31\theo\software_uploads to \\10.0.0.31\theo\software_uploads on theoCom1
    2023-12-20 08:30:49,403 [20] INFO Toems_Service.Workflows.FolderSync Replicating Folder client_versions From \\10.0.0.31\theo\client_versions to \\10.0.0.31\theo\client_versions on theoCom1
    2023-12-20 08:30:49,628 [20] INFO Toems_Service.Workflows.FolderSync Replicating Folder software_uploads From \\10.0.0.31\theo\software_uploads to \\10.0.0.31\theo\software_uploads on theoCom1
    2023-12-20 12:30:12,495 [41] INFO Toems_Service.Workflows.FolderSync Replicating Folder client_versions From \\10.0.0.31\theo\client_versions to \\10.0.0.31\theo\client_versions on theoCom1
    2023-12-20 12:30:12,721 [41] INFO Toems_Service.Workflows.FolderSync Replicating Folder software_uploads From \\10.0.0.31\theo\software_uploads to \\10.0.0.31\theo\software_uploads on theoCom1
    

    Multicast.log

    No entries from today


  • Remembered Verbose usually exists, the server is replying 404

    curl verbose.jpg

    Logs from IIS confirm, I can include them if they're useful but I don't see anything useful here.


  • I had the thought, right now Process_File_Copy() is downloading the archives via curl, via the com server API, and I use SMB Direct so there's no reason to do it that way.

    I thought maybe the 404 is happening because I don't have any of the files replicated onto the com server, I tried copying <storage>\software_uploads to C:\toems_local_storage\, this didn't work but I don't think the server config knows about this file location anymore. I would have to dive into the api code and I can't do that right now.

    Since it should be using SMB for this anyway, I implemented that, and now it seems to be working

    I can provide the code, but I'm not quite happy with some rough edges it has, I've made a lot of other tweaks along the way, and ultimately this solution is derived from existing code; also the codeblocks here don't know about powershell and make a visual mess of it.

    One additional note, the call to Expand-Archive doesn't use -force, which means it can't overwrite. I didn't locate the overwrite value so I just hard-forced it, which won't matter for my case. It should probably be something like -force:$file.Overwrite